-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2026-08-28 18:02:27 CEST. -- Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:00 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:00 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:00 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:00 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.120:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 13 Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:00 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:00 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 13 Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:01 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:01 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:01 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:01 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:02 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:02 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:03 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:03 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:03 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:03 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:04 volumio go-librespot[1383]: time="2026-08-28T18:01:04+02:00" level=debug msg="fetched chunk 12/26, size: 524288" uri="spotify:track:5XtxmIyT1OxtD3pysYMt3v" Aug 28 18:01:04 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:04 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:04 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:04 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:05 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:05 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:05 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:05 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:06 volumio volumio[1148]: info: Received OAUTH Data Aug 28 18:01:06 volumio volumio[1148]: info: Executing Spotify Oauth Login Aug 28 18:01:06 volumio volumio[1148]: info: Saving Spotify Refresh Token Aug 28 18:01:06 volumio volumio[1148]: info: New Spotify access tokenBQCztpV1EZ... Aug 28 18:01:06 volumio volumio[1148]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 28 18:01:06 volumio volumio[1148]: SPOTIFY: User informations: {"account_id":"m4VMKZtCps","country":"FR","display_name":"Guillaume","email":"guillaume.chaput@free.fr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/guigs666"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/guigs666","id":"guigs666","images":[],"product":"premium","type":"user","uri":"spotify:user:guigs666"} Aug 28 18:01:06 volumio volumio[1148]: info: Creating Spotify config file Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 18:01:06 volumio volumio[1148]: info: Spotify config file written Aug 28 18:01:06 volumio sudo[3552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 28 18:01:06 volumio sudo[3552]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:01:06 volumio systemd[1]: Stopping go-librespot Daemon... Aug 28 18:01:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 28 18:01:06 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Aug 28 18:01:06 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:06 volumio volumio[1148]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 28 18:01:06 volumio volumio[1148]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 28 18:01:06 volumio volumio[1148]: info: Connection to go-librespot Websocket closed Aug 28 18:01:06 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:06 volumio go-librespot[3554]: go-librespot daemon starting... Aug 28 18:01:06 volumio sudo[3552]: pam_unix(sudo:session): session closed for user root Aug 28 18:01:06 volumio volumio[1148]: info: New Spotify access tokenBQClbMr9i9... Aug 28 18:01:06 volumio volumio[1148]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="app state loaded" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:06 volumio volumio[1148]: SPOTIFY: User informations: {"account_id":"m4VMKZtCps","country":"FR","display_name":"Guillaume","email":"guillaume.chaput@free.fr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/guigs666"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/guigs666","id":"guigs666","images":[],"product":"premium","type":"user","uri":"spotify:user:guigs666"} Aug 28 18:01:06 volumio volumio[1148]: info: Spotify Successfully logged in Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 18:01:06 volumio volumio[1148]: info: [1787932866529] CoreMusicLibrary::Adding element Spotify Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 18:01:06 volumio volumio[1148]: Cannot find translation for source TIDAL Aug 28 18:01:06 volumio volumio[1148]: Cannot find translation for source Spotify Aug 28 18:01:06 volumio sudo[3579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 18:01:06 volumio sudo[3579]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:01:06 volumio sudo[3579]: pam_unix(sudo:session): session closed for user root Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=info msg="zeroconf server listening on port 34695" Aug 28 18:01:06 volumio sudo[3582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 18:01:06 volumio sudo[3582]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:01:06 volumio sudo[3582]: pam_unix(sudo:session): session closed for user root Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:06 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:06 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="obtained new client token: AAHnMyD+0mpy/tH2xijwUpelbZeX1+2CkckyJcKYn9I5rv7t6KILxzSbqTW9Ta2MeRtEW0AL5jacpsOhgWuoTQd0t3oYv9RA0pac335xjgyUXWuFJf8KIHnz/TK0pFRiFvna8BUH/WULJWiv4LTdtWRiinxHuVoKOua8fugfJ9MbATkovTqBQQA/8T6V7Iou819vmEhsbYSwK/ISzJpD1Z7jYxo4HkgK2LH6ybOaD8ccS2g21EDjYJ8=" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=debug msg="completed challenge" Aug 28 18:01:06 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121 from 192.168.0.30 UA: Mozilla/5.0 (Linux; Android 17; Pixel 8 Build/CP2A.260805.005; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:06 volumio go-librespot[3554]: time="2026-08-28T18:01:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetVisibleSources Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 28 18:01:06 volumio volumio[1148]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 28 18:01:06 volumio volumio[1148]: info: Received Get System Info Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:06 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:06 volumio volumio[1148]: info: Listing playlists Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 28 18:01:06 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 18:01:07 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 28 18:01:07 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:07 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:07 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:07 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 18:01:08 volumio volumio[1148]: info: Received Get System Info Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:08 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:08 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:08 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:08 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 18:01:09 volumio volumio[1148]: info: Received Get System Info Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:09 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:09 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:09 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:09 volumio volumio[1148]: info: go-librespot daemon successfully initialized Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:09 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:09 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:09 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 28 18:01:10 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:10 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:10 volumio go-librespot[3584]: go-librespot daemon starting... Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="app state loaded" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=info msg="zeroconf server listening on port 45883" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="obtained new client token: AAHSKg7Sc+1vtTQERfmEOF47FMpPhO6Ii2gnSOr1dkSxpAt0eVKBK/dUPu6reztOCRZ6bKY7ZSE/4kla2QvDAa11ltJeyslAfYzcxfZpHtXvlBtQN+vxpo7nrXYMNLzg+7xACMELXjbgDFwXw7lDrxkYqhIydYnZVjXmQ8Da3lc2/nj0Zer29aQsK/ky5P9uBktP4kB+gjfmeptim6LQJrbBCeIydj8N6tFk6vO6kO4HOKpw6NFefaE=" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:10 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=debug msg="completed challenge" Aug 28 18:01:10 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:10 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:10 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:10 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:10 volumio go-librespot[3584]: time="2026-08-28T18:01:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:11 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:11 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:11 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:11 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:12 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:12 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:12 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:12 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:12 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:12 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:12 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:12 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:13 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:13 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:13 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:13 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 28 18:01:13 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:13 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:13 volumio go-librespot[3594]: go-librespot daemon starting... Aug 28 18:01:13 volumio go-librespot[3594]: time="2026-08-28T18:01:13+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:13 volumio go-librespot[3594]: time="2026-08-28T18:01:13+02:00" level=debug msg="app state loaded" Aug 28 18:01:13 volumio go-librespot[3594]: time="2026-08-28T18:01:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=info msg="zeroconf server listening on port 41979" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="obtained new client token: AAFthG4w4nBwSy3NzYdbGS5SuS3UYbI6twiqKJWJx4HmSXbLEU6ODMQdNdzwSkTE+Rse8HDXS1eOcXCjuLOZdiGeCH5c5aZfwPjvDykSRuUk2lAg1tdU41VPL5jX35Hil6Hf1RL3Cm9iQqUOo5BYHNgVH48yY0pc7j0NJl68VtfgE3EvcvWVpvTbbbh0ucQF/aM0z20kaXoovrrRrqEW+TlOef5Rw4JPGSKGaSo+n0yLCB0AOwUS" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=debug msg="completed challenge" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:14 volumio go-librespot[3594]: time="2026-08-28T18:01:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:14 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:14 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:14 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:14 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:15 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:15 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:15 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:15 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:15 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:15 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:16 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:16 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:16 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:16 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:16 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 28 18:01:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 28 18:01:17 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:17 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:17 volumio go-librespot[3618]: go-librespot daemon starting... Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="app state loaded" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=info msg="zeroconf server listening on port 45569" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="obtained new client token: AAF7j3KMVqwgXZS+94TOjV2sha8DzbAdMryENbFmohaACaXjCKuQ9s7O+0h2bTM5xMxie7dVPtvVSPORwxUoUDaq2cgc0nKKB+mXDN1gJayhZ7dkCTxM4EGznQCCHH+GB1vU0qKyzFgH28KRY9g/W8C8X0WBROcTI0yZ58pxj91Keez8EWhF8czYFx1VzFYzNaTqG8BRS7Y2etvT6cxWo2A5EWPROvXkbNdvgxDwhJD2r7N8pOxzB44=" Aug 28 18:01:17 volumio go-librespot[3618]: time="2026-08-28T18:01:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:17 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:17 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:17 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:17 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:18 volumio go-librespot[3618]: time="2026-08-28T18:01:18+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:18 volumio go-librespot[3618]: time="2026-08-28T18:01:18+02:00" level=debug msg="completed challenge" Aug 28 18:01:18 volumio go-librespot[3618]: time="2026-08-28T18:01:18+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:18 volumio go-librespot[3618]: time="2026-08-28T18:01:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:18 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:18 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:18 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:18 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:18 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:18 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:19 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:19 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:19 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:19 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:20 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:20 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:20 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:20 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:21 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:21 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 28 18:01:21 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:21 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:21 volumio go-librespot[3628]: go-librespot daemon starting... Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="app state loaded" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:21 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:21 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=info msg="zeroconf server listening on port 42485" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="obtained new client token: AAG/9UVS2/R5gC4+xG7/Hey08eR2fM8aO2uU/jo6vSkdm/nTjOenkMeKJYLE4hZKIhg+H6dTeQGQq/jYRo1oWaHQfmOQX7DJTrgqHtFW6grMQO4ljiFQqQzTBY/0kzh6eNiqz1ZJCGTQ17xwT0eJtF2TX60zmbQsZYAJJi1vvlJ6HRzVmdVW1JeO4qPmX+O+TIj46RpyEV1Q5s1q9qWw5cWoi6xTR+YlpxlgoJ9TmT0eKNKSLFxp1uw=" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=debug msg="completed challenge" Aug 28 18:01:21 volumio go-librespot[3628]: time="2026-08-28T18:01:21+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:22 volumio go-librespot[3628]: time="2026-08-28T18:01:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:22 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:22 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:23 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:23 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:23 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:23 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:24 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:24 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:24 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:24 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 18:01:24 volumio volumio[1148]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 28 18:01:24 volumio volumio[1148]: info: Received Get System Version Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 18:01:24 volumio volumio[1148]: info: Received Get System Info Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:24 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:24 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 28 18:01:25 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:25 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:25 volumio go-librespot[3639]: go-librespot daemon starting... Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="app state loaded" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=info msg="zeroconf server listening on port 36017" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="obtained new client token: AAH3A2olB/OogwWTuG7Wm3c2JYgW6VwrAVxgeUO3RVj1PEGInQ9LxkN8EoZGrTvsteyM0KuuZsifRoL4J+iTHtoz8kip6Fv3mm0aWi+rHcr/X8Fw9ExPdBqmAGFNrPyUwmQU6CtDIVUTLHpfx90ej0ptvCmYfamMq6nOO4jz+ShdGs2s0/NefCcHyVcBSpVOGbLOPb7sq6rb4psBUMoemEfc/dXLW118uC/5FHyPIiXcyrKxWtKxO1k=" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=debug msg="completed challenge" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:25 volumio go-librespot[3639]: time="2026-08-28T18:01:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:25 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:25 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:25 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:25 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:26 volumio volumio[1148]: info: CoreCommandRouter::volumioPause Aug 28 18:01:26 volumio volumio[1148]: info: CoreStateMachine::pause Aug 28 18:01:26 volumio volumio[1148]: info: CoreStateMachine::stPlaybackTimer Aug 28 18:01:26 volumio volumio[1148]: info: CoreStateMachine::servicePause Aug 28 18:01:26 volumio volumio[1148]: info: CoreCommandRouter::servicePause Aug 28 18:01:26 volumio volumio[1148]: info: Spotify Received pause Aug 28 18:01:26 volumio volumio[1148]: SPOTIFY: SPOTIFY PAUSE Aug 28 18:01:26 volumio volumio[1148]: SPOTIFY: {"status":"play","title":"Letter","artist":"Yosi Horikawa","album":"Vapor","albumart":"https://i.scdn.co/image/ab67616d00001e02c8ac509ac96449263a351d03","uri":"spotify:track:5XtxmIyT1OxtD3pysYMt3v","trackType":"spotify","codec":"ogg","seek":0,"duration":264,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Aug 28 18:01:26 volumio volumio[1148]: info: Sending Spotify command to local API: /player/pause Aug 28 18:01:26 volumio volumio[1148]: error: Failed to send command to Spotify local API: /player/pause: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:26 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:26 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:26 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:26 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:27 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:27 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:27 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:27 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:27 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:27 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 28 18:01:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:28 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:28 volumio go-librespot[3663]: go-librespot daemon starting... Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="app state loaded" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:28 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:28 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:28 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:28 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=info msg="zeroconf server listening on port 36683" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="obtained new client token: AAGVKDk/p7mJdTLv85M5ZpN/0KVfLxa8kuxi9tzzIU8a9ubugWjMdVJUjDH48W7ixuOxCoyEWy9KmS2vMcA5IgvszA4y017LN7lYXTLGs52iVsC1motjaBqjg4n00h8scbpVFL5o3POXeqpKjij9Ud2lgYaLqWwiALoOgC9c/oSp55ZDiv3aR65wRiezKd5Jv7YE0REX1ixPSjRjtBK4BeY9gWtQ3PTVIaC0Xdut1MgX0JHZ14guoO8=" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=debug msg="completed challenge" Aug 28 18:01:28 volumio go-librespot[3663]: time="2026-08-28T18:01:28+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:29 volumio go-librespot[3663]: time="2026-08-28T18:01:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:29 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:29 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:29 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:29 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:30 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:30 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:30 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:30 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:30 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:30 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:31 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:31 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:31 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:31 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 28 18:01:32 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:32 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:32 volumio go-librespot[3674]: go-librespot daemon starting... Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="app state loaded" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=info msg="zeroconf server listening on port 38925" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="obtained new client token: AAFvIGTGwDmGn3AiN1MZKCRd/CngzPqkXO+zK/tjc5H40JKhTg0B0T+DoKP9RIVs1dwzbZL1N0w0Jf+WV+Z+6FZe63ZrC9++A+ApCFDY8ENvoO8ocQQbd/+MGSTz4Fzn8CzsIx5jskpAnl1D4rNhi6OBtCNTrvropycyJrzsU9Pd1SNCd73zOo1BLSHnub1Bh5yHnrIxpnnNiMiqtwldmyrszg8ocTGWJGDLw1JSQgGSwt07J7vLq8M=" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=debug msg="completed challenge" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:32 volumio go-librespot[3674]: time="2026-08-28T18:01:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:32 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:32 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:32 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:32 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:33 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:33 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:33 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:33 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:33 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:33 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:34 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:34 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:34 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:34 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 28 18:01:35 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:35 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:35 volumio go-librespot[3684]: go-librespot daemon starting... Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="app state loaded" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:35 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:35 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:35 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:35 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=info msg="zeroconf server listening on port 45521" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="obtained new client token: AAFUmY4rxGdYqRXBma1+8mB9p3dVC4gmmBTj1XTyVes9SVMoKOwr8RzKLHeebYGgRKIA1s/PYVf2MwNgR9zGrdq1f5aXovpfpb2foEBYfnGyt2g18JyEgpFN/NLkyga0mktirdavDf25uEE6dHTGyeI43Q65RnExesOrzBOJLaRFGAKickjGb5BWg3boZNxlZTXbhuaCHEA+igLke7Mq2stJVV9Uv7VR0iv/GM+QfVD3pF90tWJvlCM=" Aug 28 18:01:35 volumio go-librespot[3684]: time="2026-08-28T18:01:35+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:36 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:36 volumio go-librespot[3684]: time="2026-08-28T18:01:36+02:00" level=debug msg="new websocket client" Aug 28 18:01:36 volumio volumio[1148]: info: Connection to go-librespot Websocket established Aug 28 18:01:36 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:36 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:36 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:36 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:37 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:37 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:37 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:37 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:37 volumio go-librespot[3684]: time="2026-08-28T18:01:37+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:37 volumio go-librespot[3684]: time="2026-08-28T18:01:37+02:00" level=debug msg="completed challenge" Aug 28 18:01:37 volumio go-librespot[3684]: time="2026-08-28T18:01:37+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:38 volumio go-librespot[3684]: time="2026-08-28T18:01:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:38 volumio volumio[1148]: info: Connection to go-librespot Websocket closed Aug 28 18:01:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:38 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:38 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:38 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:38 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:39 volumio volumio[1148]: info: Getting Spotify volume Aug 28 18:01:39 volumio volumio[1148]: (node:1148) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:39 volumio volumio[1148]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 28 18:01:39 volumio volumio[1148]: (Use `node --trace-warnings ...` to show where the warning was created) Aug 28 18:01:39 volumio volumio[1148]: (node:1148) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Aug 28 18:01:39 volumio volumio[1148]: (node:1148) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Aug 28 18:01:39 volumio volumio[1148]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 28 18:01:39 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:39 volumio volumio[1148]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 28 18:01:39 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:39 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:39 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:39 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:40 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:40 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:40 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:40 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:40 volumio ntpd[808]: 54.36.61.42 local addr 192.168.0.121 -> Aug 28 18:01:41 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:41 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 28 18:01:41 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:41 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:41 volumio go-librespot[3708]: go-librespot daemon starting... Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="app state loaded" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=info msg="zeroconf server listening on port 34975" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="obtained new client token: AAE16LRKda8Cq7TsPszuzaUZCAQUD+sjpHB5jJtgIsVh8SPS+c1nPDDRESNI5X3jaBbUmLgpB6HOR3e8lHHoWnBoF53X0XYy2ETPTbZPdZjIEQpvaBYldQ3sbAmmQ54AEA5g6E6gdayQ6bBUgxtWFIaDAMDPf/0f50xAtB7sGwIiY9G54xVh4nmS55Tuv9sFFHnDRYc+TZqdEyn/hilTWVqfgPBo6nHbR2xQZquDNb/wdp9XyMOnRvg=" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=debug msg="completed challenge" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:41 volumio go-librespot[3708]: time="2026-08-28T18:01:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:41 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:41 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:41 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:41 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:42 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:42 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:42 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:42 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:43 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:43 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:43 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:43 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:44 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:44 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 28 18:01:44 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:44 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:44 volumio go-librespot[3718]: go-librespot daemon starting... Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="app state loaded" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:01:44 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=info msg="zeroconf server listening on port 43569" Aug 28 18:01:44 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:44 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:44 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="obtained new client token: AAHZV/041Iw+klnURlc9T/D6Sz/CyNilAZA29UaWDdz6y95LoxW5vVOlUMD3XJ04IEBrc1bftRan2xKc4TnkfkDC70jHaxt7Jph8H//LbRR54LxrW9ae948unDncBb/SxLuD3buqtB2Uu+yGyT9EpnEJ8YC/Wol4r9e3XJ3npRU5ERrq6CzlFjRNZNv5adGpVmZ0Sc6coLrtmprcHWXIa6zZ5H3Vo99EWC2ZnCq8Ie8n4ZSMiY6kfSk=" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=debug msg="completed challenge" Aug 28 18:01:44 volumio go-librespot[3718]: time="2026-08-28T18:01:44+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:45 volumio go-librespot[3718]: time="2026-08-28T18:01:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:45 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:45 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:45 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:45 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:46 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:46 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:46 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:46 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:47 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:47 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.400+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.407+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=6.892905ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.414+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=14.397524ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.418+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=17.981937ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.421+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=http://pushupdates.volumio.org duration=20.069261ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.434+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://google.com duration=34.30512ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.507+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://securetoken.googleapis.com duration=106.419626ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.507+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://www.googleapis.com duration=106.57055ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.517+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=116.831131ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.540+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://functions.volumio.cloud duration=139.365283ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.541+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://functions.volumio.cloud duration=139.853147ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.654+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=https://database.volumio.cloud duration=253.248473ms Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.710+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=http://cddb.volumio.org duration=309.998876ms Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:47 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:47 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:47 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:47 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.120:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:47 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:47 volumio volumio5-onboarding[1303]: time=2026-08-28T18:01:47.827+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.84094217s timeout=10s endpoint=http://plugins.volumio.org duration=426.476696ms Aug 28 18:01:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 28 18:01:48 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:48 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:48 volumio go-librespot[3743]: go-librespot daemon starting... Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="app state loaded" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=info msg="zeroconf server listening on port 46515" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="obtained new client token: AAFOsiNaSjW40bCWn/CS4MmVNH5a169Bj25lcM5idzdexXa4SnsBfUwadap9V4gngiErhjKcJbk9nx6YM6a1mny1PhFgwO2ZDHHdzE1Jur80+NGcZFKqg0eTiOO3hX2sodUV5gYHaJq8bHlX3GH8s85EC6FZyjkQ7bfa7+s7s+RDP8IalX5dKNUwIMHCAkWTZjYykahY/7X+HT1wXNJx8cNwTvfSvYQElMgRzVy2u1gsh25MgOQmiSI=" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=debug msg="completed challenge" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:48 volumio go-librespot[3743]: time="2026-08-28T18:01:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:48 volumio volumio[1148]: info: CoreCommandRouter::volumioPause Aug 28 18:01:48 volumio volumio[1148]: info: CoreStateMachine::pause Aug 28 18:01:48 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:48 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:48 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:48 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:49 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:49 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:49 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:49 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:50 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:50 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:50 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:50 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:50 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:50 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 28 18:01:51 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:51 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:51 volumio go-librespot[3754]: go-librespot daemon starting... Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="app state loaded" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=info msg="zeroconf server listening on port 39925" Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:51 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:51 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="obtained new client token: AAHKPZRWmMmrejdk/XvquQEKCompL6EzMYXL7Uue7wPqJt/tNBC+bY7d/D4U/HFQkG1kw4rsRBm1jn9hMr3YFFoYrUT1FJHF5OqRjRvgTG3zVqmZQe1eUdQj/2CWAro3WGpbD1hZWEycqSL71LoD9QBel4d7QZnkQGIwgpHEwhMY4SarU/YaPaMAd3SojHL5evLU/MTh/RR9i6IdEumXlQVpwWB8LhyWHoTGznXT7Uu6Fnkj+guNGOk=" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=debug msg="completed challenge" Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:51 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:51 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:51 volumio go-librespot[3754]: time="2026-08-28T18:01:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:52 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 28 18:01:52 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:52 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:52 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:52 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:52 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:52 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:53 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:53 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:53 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:53 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:53 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:53 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:54 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:54 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:54 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:54 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 28 18:01:55 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:55 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:55 volumio go-librespot[3764]: go-librespot daemon starting... Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="app state loaded" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=info msg="zeroconf server listening on port 45673" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="obtained new client token: AAF/f1ZdcTnb+oDlr75fVMhM4OhauOGhZlnKGVW5G3agu45BxhIoBU79VvToAIKz5TY53/jO1lk1v2H6bZgGacfKR3CZRVDvBvdAPOFTppGPKbL8tosjJ31dpCe8ysdIGALwgBe3yh2wRgM7/G1dbjNKE1zjDQiATZXeZzuJDAg4TFA3kV/aFYlpQB9yRz1ZCVm2ypBD5Os4oRk3xQlzMEuMLxTEnJDY+vb7hWmnmT2MeKwG/rCMzCE=" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=debug msg="completed challenge" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:55 volumio go-librespot[3764]: time="2026-08-28T18:01:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:01:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:55 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:55 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:01:55 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:01:55 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:01:55 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:01:56 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:56 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:56 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:56 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:56 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:56 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:57 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:57 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:57 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:57 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:01:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 28 18:01:58 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:01:58 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:01:58 volumio go-librespot[3789]: go-librespot daemon starting... Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="app state loaded" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=info msg="zeroconf server listening on port 46483" Aug 28 18:01:58 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:58 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:58 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:58 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="obtained new client token: AAH1uoTxipXb4U/W02rxBFH2rYhrKVilFN8M8B509ARJjmlSRbXiD785ENQuPe3SQBJGIV4rh2TH4NNQ5wNiMCr2udbthepJh6RdYTxFjkgnot9DZuzMxq+YXcjcezjmnr13T7ZcurONErJo+nGoDaN+qwZ1RaXOuOLWsEibDxmEU4NaIa669s6iMsT6T4PyurhuQ+NV7fgCPuTi6jwB8kkMOyybvEEmhilJhlwMG0on4lMDPM+RBHg=" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="completed keyexchange" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=debug msg="completed challenge" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01:58+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:01:58 volumio go-librespot[3789]: time="2026-08-28T18:01: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 28 18:01:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:01:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:01:59 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:01:59 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:01:59 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:01:59 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:01:59 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:01:59 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:00 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:00 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:00 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:00 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:00 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.193+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842832877s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.217+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.225+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=8.025983ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.231+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=14.097123ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.235+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=18.207493ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.237+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=http://pushupdates.volumio.org duration=20.215576ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.249+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://google.com duration=32.496946ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.320+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://securetoken.googleapis.com duration=102.962967ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.325+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://www.googleapis.com duration=108.397949ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.331+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=114.096112ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.337+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://database.volumio.cloud duration=119.523001ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.348+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://functions.volumio.cloud duration=130.80944ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.348+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=https://functions.volumio.cloud duration=131.600114ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.378+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=http://cddb.volumio.org duration=160.505498ms Aug 28 18:02:01 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:01.481+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.842888304s timeout=10s endpoint=http://plugins.volumio.org duration=263.648814ms Aug 28 18:02:01 volumio sudo[3838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 18:02:01 volumio sudo[3838]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:02:01 volumio sudo[3838]: pam_unix(sudo:session): session closed for user root Aug 28 18:02:01 volumio sudo[3841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 18:02:01 volumio sudo[3841]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:02:01 volumio sudo[3841]: pam_unix(sudo:session): session closed for user root Aug 28 18:02:01 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121 from 192.168.0.30 UA: Mozilla/5.0 (Linux; Android 17; Pixel 8 Build/CP2A.260805.005; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 28 18:02:01 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:01 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:01 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:01 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:01 volumio sudo[3844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 18:02:01 volumio sudo[3844]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:02:01 volumio sudo[3844]: pam_unix(sudo:session): session closed for user root Aug 28 18:02:01 volumio sudo[3847]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 18:02:01 volumio sudo[3847]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 18:02:01 volumio sudo[3847]: pam_unix(sudo:session): session closed for user root Aug 28 18:02:02 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121 from 192.168.0.30 UA: Mozilla/5.0 (Linux; Android 17; Pixel 8 Build/CP2A.260805.005; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Aug 28 18:02:02 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 28 18:02:02 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 28 18:02:02 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetVisibleSources Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 28 18:02:02 volumio volumio[1148]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 28 18:02:02 volumio volumio[1148]: info: Received Get System Info Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:02 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:02 volumio volumio[1148]: info: Listing playlists Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 18:02:02 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:02 volumio go-librespot[3849]: go-librespot daemon starting... Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="app state loaded" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=info msg="zeroconf server listening on port 45825" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="obtained new client token: AAHAWTuHHLjvQKsRPflWkbCa2biRr+AORXa2vb6JGBzMf9Dj5VbeTwj8Hxr5vr8l2G7f63wu2sG1bz/NRu2ViIe8fkHXlJ8JZfEw+V0IEEekt30bV87UXqLMC2nzcuOK52XuY10Z6M18rHr09o8UbJQ4Ixe9FlbWzNcDsnHwR8mwFUrNWQnehhCpr+LvcWyVF4/CVM4cdWm8pR1NyDa3BBb1huCDKcK451++7gau5cQSnFhwGswGYck=" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=debug msg="completed challenge" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:02 volumio go-librespot[3849]: time="2026-08-28T18:02:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:02:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:02 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:02 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:02 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::volumioPause Aug 28 18:02:03 volumio volumio[1148]: info: CoreStateMachine::pause Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:03 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:03 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 18:02:03 volumio volumio[1148]: info: Received Get System Info Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:03 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:03 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 18:02:04 volumio volumio[1148]: info: Received Get System Info Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:04 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:04 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:04 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:04 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:05 volumio volumio[1148]: info: CoreCommandRouter::volumioNext Aug 28 18:02:05 volumio volumio[1148]: info: CoreStateMachine::next Aug 28 18:02:05 volumio volumio[1148]: info: Spotify next Aug 28 18:02:05 volumio volumio[1148]: info: Sending Spotify command to local API: /player/next Aug 28 18:02:05 volumio volumio[1148]: error: Failed to send command to Spotify local API: /player/next: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:05 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:05 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 28 18:02:05 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:05 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:05 volumio go-librespot[3860]: go-librespot daemon starting... Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="app state loaded" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=info msg="zeroconf server listening on port 43667" Aug 28 18:02:05 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="obtained new client token: AAEWdXacytObyAitvdYXFpMD1FeMn5VVfWAhtHj5idkSLHrB6ZAbbpXnYbqJr3yy7oc15mkNWk+6ikBwIAtyNUP1GoHsE/cRtPPh0ZbOISITYZSYtDV4NbsexLC7Y+cqprM7ZOjoiDVBVyt7M0+kXRAdb76+OrlstbyS4T6lbQVyE8V/vNlCkdcu0hZft1XvTg+Xwou25u69ZNet9KYGRTelwkvwIk7CCeMAMlj3Op/8u6Jqmnh/AQE=" Aug 28 18:02:05 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:05 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:05 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 28 18:02:05 volumio go-librespot[3860]: time="2026-08-28T18:02:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 28 18:02:06 volumio go-librespot[3860]: time="2026-08-28T18:02:06+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:06 volumio go-librespot[3860]: time="2026-08-28T18:02:06+02:00" level=debug msg="completed challenge" Aug 28 18:02:06 volumio go-librespot[3860]: time="2026-08-28T18:02:06+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:06 volumio go-librespot[3860]: time="2026-08-28T18:02:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:02:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:06 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:06 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:06 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:07 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:07 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:07 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:07 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:08 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:08 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:08 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:08 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:08 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:08 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 28 18:02:09 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:09 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:09 volumio go-librespot[3885]: go-librespot daemon starting... Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="app state loaded" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=info msg="zeroconf server listening on port 33201" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="obtained new client token: AAHpPVYRGeWXFeoR9zbcG/XGvWKS/Iqn+28JFLiYskSYZIo8d3/uujgf9jO1gMJnmhGIwYUCwa/RiiiK9Xar9idRhUHocLArh7fVC/Q9io1m3uoP/uKNWQtIPZpa1Qab8tE9zY2CxupX0K8vOCfsyvsgnNOBcgfsKcB3uvWb2orqjhV3Z7XiBRxmfDtyF5LomBFTQUt05sdZGFvSzGWbaUFFOCKoQGjNmkMWzTJzddmvHq1eA6kU7JY=" Aug 28 18:02:09 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:09 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:09 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:09 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=debug msg="completed challenge" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02:09+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:09 volumio go-librespot[3885]: time="2026-08-28T18:02: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 28 18:02:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:10 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:10 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:10 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:10 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:11 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:11 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:11 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:11 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:11 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:11 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:12 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 28 18:02:12 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:12 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:12 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:12 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 28 18:02:13 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:13 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:13 volumio go-librespot[3895]: go-librespot daemon starting... Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="app state loaded" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=info msg="zeroconf server listening on port 45013" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="obtained new client token: AAG063jngFz4DYku8UZbdF22NJzbZxPV7K7vxo2DzQqIPQl/xAhACXOsHAZZ3LHtSNscZ3HVGoVw2u4PKeM9VdT8t8RoZQh9Vtictd8dBNLziZMFaesowBUkm2LDt7kdFkOr/LB+RYBNlcmVanT1b/6iR6Avn3rBMWUsUmr3Duv5sQeh/klfXJinhtW08puD/Jx1MWw0BwIgYVvrRazQSdiCz1x+Vf1B4ba1zph1Rvpka6ZmY+4wdxQ=" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=debug msg="completed challenge" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02:13+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:13 volumio go-librespot[3895]: time="2026-08-28T18:02: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 28 18:02:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:13 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:13 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:13 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:13 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:14 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:14 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:14 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:14 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:14 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:14 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:15 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:15 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:15 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:15 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 28 18:02:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:16 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:16 volumio go-librespot[3911]: go-librespot daemon starting... Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="app state loaded" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=info msg="zeroconf server listening on port 42757" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="obtained new client token: AAE2w4qWNb1w+YKZa9Fs6i1Kxj3COL+80VYm7CSnp1kko22K4Vft/u3RJpQcS5JHvVUn8M8WKinJWUUAnK7a6rVGLYkQGpS+KR0oJW22S7fzGZBxl2YJofuadN+mD6cSgTNAfioyrcWVplst0QvxSBfMvZwV70y8JSsxj9OWvIxz4XDadd6FJgdTWBaoCxM49Wju5fFKwDyJQgnl5ceQ+XpQwq8tKo40U8Z79Jo7CSj+81rM29rNYZ4=" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:02:16 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:16 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:16 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:16 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=debug msg="completed challenge" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02:16+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:16 volumio go-librespot[3911]: time="2026-08-28T18:02: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 28 18:02:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:17 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:17 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:17 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:17 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:17 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:17 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:18 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:18 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:18 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:18 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:19 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:19 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:19 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:19 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:20 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:20 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 28 18:02:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:20 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:20 volumio go-librespot[3932]: go-librespot daemon starting... Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="app state loaded" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=info msg="zeroconf server listening on port 34801" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="obtained new client token: AAE4YfvNSaOngms3D74GLbiTCrtpIXrRg1a6L8QRhXMoZHNlgey/3emAXlXPAzfIP0oIyC3TGaWYacjYTOAptafk3r73+9rkCgeHWt9lobrSXixsz3p+MX51T6tl148UULGPv6X1FrcT1aetX/Tg62P6T6lnsDvIvzBLkr9LO4Q7RwOm9mYXbfBtorvKc8kCY/HpqBFOYUJIAq6bIoHn7LFEhmW5Sc3RRCiO8XzZulMXzvtxhjv0l9M=" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 28 18:02:20 volumio go-librespot[3932]: time="2026-08-28T18:02:20+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 28 18:02:20 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:20 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:20 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:20 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 18:02:21 volumio volumio[1148]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 28 18:02:21 volumio volumio[1148]: info: Received Get System Version Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 18:02:21 volumio volumio[1148]: info: Received Get System Info Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:21 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.427+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.437+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=9.498983ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.442+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=14.267457ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.448+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=http://pushupdates.volumio.org duration=20.524799ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.448+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=20.851979ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.464+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://google.com duration=36.421104ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.532+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://securetoken.googleapis.com duration=104.545078ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.535+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://www.googleapis.com duration=107.427447ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.545+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=118.122785ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.551+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://database.volumio.cloud duration=124.063316ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.564+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://functions.volumio.cloud duration=136.584185ms Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.590+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=https://functions.volumio.cloud duration=162.885703ms Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:21 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:21 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.834+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=http://plugins.volumio.org duration=406.444637ms Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:21 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:21 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:21 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:21 volumio volumio5-onboarding[1303]: time=2026-08-28T18:02:21.995+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.30:60384,192.168.0.30:42134 @ 0x22a29f0" latency=-1.838540263s timeout=10s endpoint=http://cddb.volumio.org duration=566.991501ms Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:22 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:22 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.120:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 18:02:22 volumio volumio[1148]: info: Discovery: Getting this device information Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 18:02:22 volumio volumio[1148]: verbose: New Socket.io Connection to 192.168.0.121:3000 from 192.168.0.30 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:22 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:22 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:22 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:23 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:23 volumio go-librespot[3932]: time="2026-08-28T18:02:23+02:00" level=debug msg="new websocket client" Aug 28 18:02:23 volumio volumio[1148]: info: Connection to go-librespot Websocket established Aug 28 18:02:23 volumio go-librespot[3932]: time="2026-08-28T18:02:23+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:23 volumio go-librespot[3932]: time="2026-08-28T18:02:23+02:00" level=debug msg="completed challenge" Aug 28 18:02:23 volumio go-librespot[3932]: time="2026-08-28T18:02:23+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:23 volumio go-librespot[3932]: time="2026-08-28T18:02:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:02:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:23 volumio volumio[1148]: info: Connection to go-librespot Websocket closed Aug 28 18:02:23 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:23 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:23 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:23 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:24 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:24 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:24 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:24 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:25 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:25 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:25 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:25 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:26 volumio volumio[1148]: info: Getting Spotify volume Aug 28 18:02:26 volumio volumio[1148]: (node:1148) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:26 volumio volumio[1148]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 28 18:02:26 volumio volumio[1148]: (node:1148) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Aug 28 18:02:26 volumio volumio[1148]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 28 18:02:26 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:26 volumio volumio[1148]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 28 18:02:26 volumio volumio[1148]: info: Initializing connection to go-librespot Websocket Aug 28 18:02:26 volumio volumio[1148]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 18:02:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 18:02:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 28 18:02:26 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 18:02:26 volumio systemd[1]: Started go-librespot Daemon. Aug 28 18:02:26 volumio go-librespot[3943]: go-librespot daemon starting... Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=info msg="running go-librespot 0.6.2" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="app state loaded" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=info msg="zeroconf server listening on port 42281" Aug 28 18:02:26 volumio volumio[1148]: info: CoreCommandRouter::volumioGetState Aug 28 18:02:26 volumio volumio[1148]: info: CoreCommandRouter::volumioGetQueue Aug 28 18:02:26 volumio volumio[1148]: info: CoreStateMachine::getQueue Aug 28 18:02:26 volumio volumio[1148]: info: CorePlayQueue::getQueue Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="obtained new client token: AAFWFvl8iAJjZEWsygisGxiavb7zvy1JXyjx3VhTlWIh0ZbBmbrQulZkdm9dNH9/iUT2khRVvU8KBvaXZZ/L7rd+g9I8rAzMj+oc7xhA5APMFQSes3nr/cNk/cVcIs9m03C2jHGaJP7ZHql4voYd3QCisf2N5vrMqPLS9UbK+iQ/1LqEEcofLTlfPrbcPhd7jrgmlQJQ4BIYv3MZVRZCF6plQESmSJqbZ9ak+Lm3vzkJae8g00raIrU=" Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 18:02:26 volumio volumio[1148]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Aug 28 18:02:26 volumio volumio[1148]: info: PLUGIN onReboot : networkfs Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="completed keyexchange" Aug 28 18:02:26 volumio volumio[1148]: info: PLUGIN onReboot : audiophonicsonoff Aug 28 18:02:26 volumio go-librespot[3943]: time="2026-08-28T18:02:26+02:00" level=debug msg="completed challenge" Aug 28 18:02:26 volumio volumio[1148]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 18:02:26 volumio volumio[1148]: TypeError: Cannot read property 'writeSync' of undefined Aug 28 18:02:26 volumio volumio[1148]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25) Aug 28 18:02:26 volumio volumio[1148]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Aug 28 18:02:26 volumio volumio[1148]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Aug 28 18:02:26 volumio volumio[1148]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Aug 28 18:02:26 volumio volumio[1148]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Aug 28 18:02:26 volumio volumio[1148]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Aug 28 18:02:26 volumio volumio[1148]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22) Aug 28 18:02:26 volumio volumio[1148]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33) Aug 28 18:02:26 volumio volumio[1148]: at Socket.emit (events.js:315:20) Aug 28 18:02:26 volumio volumio[1148]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 28 18:02:26 volumio volumio[1148]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 28 18:02:26 volumio volumio[1148]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 18:02:27 volumio go-librespot[3943]: time="2026-08-28T18:02:27+02:00" level=info msg="authenticated AP" username="gu****66" Aug 28 18:02:27 volumio go-librespot[3943]: time="2026-08-28T18:02:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 18:02:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 18:02:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 18:02:27 volumio sudo[3976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-28 18:01 Aug 28 18:02:27 volumio sudo[3976]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"