Aug 30 04:46:00 spla-repro sudo[18585]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:00 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 30 04:46:00 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:00 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:00 spla-repro go-librespot[18609]: go-librespot daemon starting... Aug 30 04:46:00 spla-repro go-librespot[18610]: time="2026-08-30T04:46:00+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:00 spla-repro go-librespot[18610]: time="2026-08-30T04:46:00+02:00" level=debug msg="app state loaded" Aug 30 04:46:00 spla-repro go-librespot[18610]: time="2026-08-30T04:46:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+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 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+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 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+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 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=info msg="zeroconf server listening on port 43483" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=debug msg="obtained new client token: AAHx5Z2zDmHnMKkjZwJUO8lSyNYBu4u+rmO5lKOAUzjscynwkVA88THjxvT+wE3xmKFph+il4ZQYfa7ichFQiLyYLB12CoMx8rwie958GuRJYMaTeIMY9Q4duUAXK+VHelbT7llMkjZQJKQ7DWteX/7hkcA2+JjImNnONq2x/nskhOzJTNv9J7oSMGv+IiGlmEmvoTjiZWaBoMjQXR9vPLIrOjFt19JgWY6UWFPClWPgMVg6E9N5oww=" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=debug msg="completed challenge" Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:01 spla-repro volumio[18538]: info: Starting UPNP Browser Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "alarm-clock"... Aug 30 04:46:01 spla-repro go-librespot[18610]: time="2026-08-30T04:46:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:01 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:01 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "airplay_emulation"... Aug 30 04:46:01 spla-repro volumio[18538]: info: Starting Shairport Sync Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "last_100"... Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "webradio"... Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "i2s_dacs"... Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "volumiodiscovery"... Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** For more information see Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 30 04:46:01 spla-repro volumio[18538]: *** WARNING *** For more information see Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** For more information see Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 30 04:46:01 spla-repro node[18538]: *** WARNING *** For more information see Aug 30 04:46:01 spla-repro volumio[18538]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 30 04:46:01 spla-repro volumio[18538]: info: Discovery: Started advertising with name: Spálňa-repro Aug 30 04:46:01 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 30 04:46:01 spla-repro volumio[18538]: info: Loading plugin "spop"... Aug 30 04:46:02 spla-repro volumio[18538]: info: Loading plugin "outputs"... Aug 30 04:46:02 spla-repro volumio[18538]: info: Loading plugin "albumart"... Aug 30 04:46:02 spla-repro volumio[18538]: info: Plugin example_plugin is not enabled Aug 30 04:46:02 spla-repro volumio[18538]: info: Loading plugin "inputs"... Aug 30 04:46:02 spla-repro volumio[18538]: info: Loading plugin "updater_comm"... Aug 30 04:46:02 spla-repro volumio[18538]: info: Plugin mpdemulation is not enabled Aug 30 04:46:02 spla-repro volumio[18538]: info: Loading plugin "rest_api"... Aug 30 04:46:03 spla-repro volumio[18538]: info: Loading plugin "websocket"... Aug 30 04:46:03 spla-repro volumio[18538]: info: Starting Socket.io Server version 1.7.4 Aug 30 04:46:03 spla-repro volumio[18538]: info: Plugin fusiondsp is not enabled Aug 30 04:46:03 spla-repro volumio[18538]: info: Loading i18n strings for locale sk Aug 30 04:46:03 spla-repro volumio[18538]: Updating browse sources language Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::initPlayerControls Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: Express server listening on port 3000 Aug 30 04:46:03 spla-repro volumio[18538]: [Metrics] WebUI: 6s 514.53ms Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::resetVolumioState Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::getcurrentVolume Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioRetrievevolume Aug 30 04:46:03 spla-repro volumio[18538]: info: Cannot read play queue from file Aug 30 04:46:03 spla-repro volumio[18538]: info: Volumio Network Manager: Network status updated: 1 Aug 30 04:46:03 spla-repro volumio[18538]: Unable to parse: Aug 30 04:46:03 spla-repro volumio[18538]: Simple mixer control 'Master',0 Aug 30 04:46:03 spla-repro volumio[18538]: Capabilities: volume volume-joined Aug 30 04:46:03 spla-repro volumio[18538]: Playback channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Capture channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Limits: 0 - 248 Aug 30 04:46:03 spla-repro volumio[18538]: Mono: 112 [45%] Aug 30 04:46:03 spla-repro volumio[18538]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 30 04:46:03 spla-repro volumio[18622]: Forking 3 albumart workers Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 30 04:46:03 spla-repro volumio[18538]: info: Received Get System Info Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 04:46:03 spla-repro volumio[18538]: info: Discovery: Getting this device information Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 30 04:46:03 spla-repro volumio[18538]: Unable to parse: Aug 30 04:46:03 spla-repro volumio[18538]: Simple mixer control 'Master',0 Aug 30 04:46:03 spla-repro volumio[18538]: Capabilities: volume volume-joined Aug 30 04:46:03 spla-repro volumio[18538]: Playback channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Capture channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Limits: 0 - 248 Aug 30 04:46:03 spla-repro volumio[18538]: Mono: 112 [45%] Aug 30 04:46:03 spla-repro volumio[18538]: info: VolumeController:: Volume=undefined Mute =false Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::pushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioPushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::updateTrackBlock Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrackBlock Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioRetrievevolume Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 04:46:03 spla-repro volumio-remote-updater[725]: [2026-08-30 04:46:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788057959 101 Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::setRepeat null single undefined Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::pushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioPushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::setRandom null Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::pushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioPushState Aug 30 04:46:03 spla-repro volumio[18538]: info: Setting Device type: Raspberry PI Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.202 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 30 04:46:03 spla-repro volumio[18538]: info: Completed loading Core Plugins Aug 30 04:46:03 spla-repro volumio[18538]: info: Preparing to generate the ALSA configuration file Aug 30 04:46:03 spla-repro volumio[18538]: Unable to parse: Aug 30 04:46:03 spla-repro volumio[18538]: Simple mixer control 'Master',0 Aug 30 04:46:03 spla-repro volumio[18538]: Capabilities: volume volume-joined Aug 30 04:46:03 spla-repro volumio[18538]: Playback channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Capture channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Limits: 0 - 248 Aug 30 04:46:03 spla-repro volumio[18538]: Mono: 112 [45%] Aug 30 04:46:03 spla-repro volumio[18538]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 30 04:46:03 spla-repro volumio[18538]: info: Discovery: adding d4caa6fc-95c1-41bd-89e0-c640d24940c4 Aug 30 04:46:03 spla-repro volumio[18538]: info: Discovery: Found device kuchyna-repro Aug 30 04:46:03 spla-repro volumio[18538]: info: Discovery: Connecting to remote: 192.168.200.201 Aug 30 04:46:03 spla-repro volumio[18538]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.202 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 30 04:46:03 spla-repro volumio[18538]: Unable to parse: Aug 30 04:46:03 spla-repro volumio[18538]: Simple mixer control 'Master',0 Aug 30 04:46:03 spla-repro volumio[18538]: Capabilities: volume volume-joined Aug 30 04:46:03 spla-repro volumio[18538]: Playback channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Capture channels: Mono Aug 30 04:46:03 spla-repro volumio[18538]: Limits: 0 - 248 Aug 30 04:46:03 spla-repro volumio[18538]: Mono: 112 [45%] Aug 30 04:46:03 spla-repro volumio[18538]: info: VolumeController:: Volume=undefined Mute =false Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreStateMachine::pushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioPushState Aug 30 04:46:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:04 spla-repro volumio[18538]: info: Discovery: adding 284e4a17-0388-4ad0-8157-75a8b67cae8e Aug 30 04:46:04 spla-repro volumio[18538]: info: Discovery: Found device kupelna-repro Aug 30 04:46:04 spla-repro volumio[18538]: info: Discovery: Connecting to remote: 192.168.200.202 Aug 30 04:46:04 spla-repro volumio[18538]: info: Asound.conf file unchanged, so no further update is needed Aug 30 04:46:04 spla-repro volumio[18538]: info: Output device has changed, restarting MPD Aug 30 04:46:04 spla-repro volumio[18538]: info: Output device has changed, restarting Shairport Sync Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:04 spla-repro volumio[18538]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 04:46:04 spla-repro sudo[18681]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro volumio[18538]: info: ___________ START PLUGINS ___________ Aug 30 04:46:04 spla-repro sudo[18684]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro sudo[18681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 04:46:04 spla-repro sudo[18681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:04 spla-repro volumio[18538]: info: ControllerMpd::onStart: Initializing MPD Aug 30 04:46:04 spla-repro volumio[18538]: info: Creating MPD Configuration file Aug 30 04:46:04 spla-repro sudo[18684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 04:46:04 spla-repro sudo[18681]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:04 spla-repro sudo[18684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 30 04:46:04 spla-repro volumio[18538]: info: [1788057964194] CoreMusicLibrary::Adding element Mediálne servery Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 04:46:04 spla-repro sudo[18691]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro sudo[18689]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro sudo[18691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 04:46:04 spla-repro sudo[18691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:04 spla-repro volumio[18538]: info: UPNP Browser: Client initialized successfully Aug 30 04:46:04 spla-repro sudo[18691]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:04 spla-repro sudo[18694]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 30 04:46:04 spla-repro sudo[18689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:04 spla-repro sudo[18694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 04:46:04 spla-repro sudo[18689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:04 spla-repro sudo[18694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:04 spla-repro volumio[18538]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:04 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 30 04:46:04 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 04:46:04 spla-repro systemd[1]: mpd.service: Consumed 5.151s CPU time. Aug 30 04:46:04 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 30 04:46:04 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 04:46:04 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 04:46:04 spla-repro volumio[18538]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 30 04:46:04 spla-repro volumio[18538]: info: [1788057964408] CoreMusicLibrary::Adding element Last_100 Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 30 04:46:04 spla-repro volumio[18538]: info: [1788057964412] CoreMusicLibrary::Adding element Webradio Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 04:46:04 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 04:46:04 spla-repro volumio[18538]: info: Initializing BBC Radios Aug 30 04:46:04 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 04:46:04 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 30 04:46:04 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 04:46:04 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 30 04:46:04 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 30 04:46:04 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 04:46:04 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 04:46:04 spla-repro sudo[18689]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:04 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 04:46:04 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:04 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:04 spla-repro go-librespot[18722]: go-librespot daemon starting... Aug 30 04:46:04 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 04:46:04 spla-repro volumio[18538]: info: Creating Spotify config file Aug 30 04:46:04 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:04 spla-repro volumio5-onboarding[21614]: time=2026-08-30T04:46:04.645+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 04:46:04 spla-repro go-librespot[18723]: time="2026-08-30T04:46:04+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:04 spla-repro sudo[18724]: root : unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro sudo[18724]: sudo: unable to resolve host spla-repro: System error Aug 30 04:46:04 spla-repro sudo[18724]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 04:46:04 spla-repro sudo[18724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 04:46:04 spla-repro sudo[18724]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:05 spla-repro go-librespot[18723]: time="2026-08-30T04:46:05+02:00" level=info msg="zeroconf server listening on port 40065" Aug 30 04:46:05 spla-repro go-librespot[18723]: time="2026-08-30T04:46:05+02:00" level=info msg="using built-in mDNS responder" Aug 30 04:46:05 spla-repro volumio[18640]: Starting albumart workers Aug 30 04:46:05 spla-repro volumio[18538]: info: Volumio Calling Home Aug 30 04:46:05 spla-repro volumio[18639]: Starting albumart workers Aug 30 04:46:05 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:05 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:05 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 30 04:46:05 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:05 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:05 spla-repro volumio[18538]: info: Discovery: adding e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 30 04:46:05 spla-repro volumio[18538]: info: Discovery: Found device Spálňa-repro Aug 30 04:46:05 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:05 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:05 spla-repro volumio[18538]: info: Discovery: Connected to remote: 192.168.200.201 Aug 30 04:46:05 spla-repro volumio[18641]: Starting albumart workers Aug 30 04:46:05 spla-repro volumio[18538]: info: MPD Permissions set Aug 30 04:46:05 spla-repro volumio[18538]: info: MPD Permissions set Aug 30 04:46:05 spla-repro volumio[18538]: info: Discovery: this is already registered, e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 30 04:46:05 spla-repro volumio[18538]: info: Discovery: Found device Spálňa-repro Aug 30 04:46:05 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:05 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:05 spla-repro volumio[18538]: info: Volumio called home Aug 30 04:46:05 spla-repro volumio[18538]: info: Spotify config file written Aug 30 04:46:06 spla-repro sudo[18739]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:06 spla-repro volumio[18538]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 30 04:46:06 spla-repro sudo[18739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 30 04:46:06 spla-repro sudo[18739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:06 spla-repro volumio[18538]: info: Discovery: Connected to remote: 192.168.200.202 Aug 30 04:46:06 spla-repro systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 30 04:46:06 spla-repro systemd[1]: go-librespot-daemon.service: Killing process 18729 (go-librespot) with signal SIGKILL. Aug 30 04:46:06 spla-repro systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 30 04:46:06 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:06 spla-repro go-librespot[18743]: go-librespot daemon starting... Aug 30 04:46:06 spla-repro sudo[18739]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=debug msg="app state loaded" Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:06 spla-repro volumio[18538]: info: No need to fix Spotify hosts Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+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 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+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 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=info msg="zeroconf server listening on port 35065" Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 30 04:46:06 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:06 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=debug msg="obtained new client token: AAFvRfUAAVWBmShGNbxB0oKldTMHoqU06GXmlP2qRmPfI6z/KkukMjTWmrIHe9VGQSW/6OwEqqsXOV4EzE3IKuBRYoUfsHMtORAqjCZu+x/mx99zuU0M2pWAijsD6peZy9EpZqILcnHko8MdH4Rqy+yoFekl82DSN+kasv520dhUT78YLYYy9Y6Kud7ZP1nHNjZbOiUqGkh80prZJwO+3eoMq0lR+UxmyNfTlk0pngytkrUTSKmAAgwWEw==" Aug 30 04:46:06 spla-repro volumio[18538]: info: Starting Shairport Sync Aug 30 04:46:06 spla-repro volumio[18538]: info: Starting Shairport Sync Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:06 spla-repro volumio[18538]: info: Starting Shairport Sync Aug 30 04:46:06 spla-repro sudo[18779]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:06 spla-repro sudo[18779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 04:46:06 spla-repro volumio[18538]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 30 04:46:06 spla-repro sudo[18779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:06 spla-repro go-librespot[18749]: time="2026-08-30T04:46:06+02:00" level=debug msg="completed challenge" Aug 30 04:46:07 spla-repro sudo[18786]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:07 spla-repro sudo[18788]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:07 spla-repro sudo[18786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 04:46:07 spla-repro go-librespot[18749]: time="2026-08-30T04:46:07+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:07 spla-repro sudo[18786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:07 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 04:46:07 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 04:46:07 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 04:46:07 spla-repro systemd[1]: shairport-sync.service: Consumed 3.923s CPU time. Aug 30 04:46:07 spla-repro sudo[18788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 04:46:07 spla-repro sudo[18788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:07 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 04:46:07 spla-repro sudo[18779]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:07 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:07 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:07 spla-repro volumio[18538]: info: Shairport-Sync Started Aug 30 04:46:07 spla-repro go-librespot[18749]: time="2026-08-30T04:46:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:07 spla-repro volumio[18538]: Error adding Membership: Error: addMembership EINVAL Aug 30 04:46:07 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:07 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:07 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 04:46:07 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 04:46:07 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 04:46:07 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 04:46:07 spla-repro sudo[18786]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:07 spla-repro sudo[18788]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:07 spla-repro volumio[18538]: info: Shairport-Sync Started Aug 30 04:46:07 spla-repro volumio[18538]: info: Shairport-Sync Started Aug 30 04:46:08 spla-repro mpd[18732]: 2026-08-30T04:46:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 30 04:46:08 spla-repro systemd[1]: Started mpd.service - Music Player Daemon. Aug 30 04:46:08 spla-repro sudo[18694]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:08 spla-repro sudo[18684]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:08 spla-repro volumio[18538]: info: Completed starting Core Plugins Aug 30 04:46:08 spla-repro volumio[18538]: info: ------------------------------------------- Aug 30 04:46:08 spla-repro volumio[18538]: info: ----- MyVolumio plugins startup ---- Aug 30 04:46:08 spla-repro volumio[18538]: info: ------------------------------------------- Aug 30 04:46:08 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 30 04:46:08 spla-repro volumio[18538]: error: MPD error: The expression evaluated to a falsy value: Aug 30 04:46:08 spla-repro volumio[18538]: assert.ok(self.idling) Aug 30 04:46:08 spla-repro volumio[18538]: error: The expression evaluated to a falsy value: Aug 30 04:46:08 spla-repro volumio[18538]: assert.ok(self.idling) Aug 30 04:46:08 spla-repro volumio[18538]: info: MPD running with PID18732 Aug 30 04:46:08 spla-repro volumio[18538]: ,establishing connection Aug 30 04:46:08 spla-repro volumio[18538]: error: MPD error: The expression evaluated to a falsy value: Aug 30 04:46:08 spla-repro volumio[18538]: assert.ok(self.idling) Aug 30 04:46:08 spla-repro volumio[18538]: error: The expression evaluated to a falsy value: Aug 30 04:46:08 spla-repro volumio[18538]: assert.ok(self.idling) Aug 30 04:46:08 spla-repro volumio[18538]: error: updateQueue error: null Aug 30 04:46:09 spla-repro sudo[18827]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:09 spla-repro sudo[18829]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:09 spla-repro sudo[18827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 30 04:46:09 spla-repro sudo[18827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:09 spla-repro sudo[18829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 30 04:46:09 spla-repro sudo[18827]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:09 spla-repro sudo[18829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:09 spla-repro sudo[18829]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:09 spla-repro sudo[18832]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:09 spla-repro sudo[18832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 30 04:46:09 spla-repro sudo[18832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:09 spla-repro sudo[18832]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:09 spla-repro volumio[18538]: info: Upmpdcli Daemon Started Aug 30 04:46:09 spla-repro volumio[18538]: info: go-librespot daemon successfully initialized Aug 30 04:46:10 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 30 04:46:10 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:10 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:10 spla-repro go-librespot[18835]: go-librespot daemon starting... Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=debug msg="app state loaded" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+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 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+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 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=info msg="zeroconf server listening on port 34731" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=debug msg="obtained new client token: AAES2nDDvGKjBR8UvDY765qKNhumy14ARFnFOslfppR/dmEPAcl7YL7o/g6D/eR+B86uFj6Q7g8QDlHMWE4CWcw72EAzEYkwaLAgaf3q3N4AdPaoT3lhhJArcTFXep8guNHcQb7DfIxYVwtGSF0pkpRPM+cmEMEu7h/qxJPVSCrYRpWN1brm/le2kmUMnPudsbHJn6oS2hWM4MaYZ/LcFsUQtWEOcb/SJWMO1hOCaRdFJ7BQap3bC3bYNg==" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=debug msg="completed challenge" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46:10+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:10 spla-repro go-librespot[18836]: time="2026-08-30T04:46: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 30 04:46:10 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:10 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:12 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:12 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:13 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:13 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:13 spla-repro volumio[18538]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 30 04:46:13 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 30 04:46:13 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:14 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:14 spla-repro go-librespot[18846]: go-librespot daemon starting... Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=debug msg="app state loaded" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+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 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+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 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=info msg="zeroconf server listening on port 34369" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=debug msg="obtained new client token: AAGYbUYesg5/WlsmoZZEcsS+Ud9rup+Tzy0OqOtM6RotMecOyMkXGsfWlhZoIIf4dVPEXRHVuQC/sboHdAZqNvxNKrb0eK4BDWECOANjo+XL9XBBkftgOUB0sW6gwnNV9yXA+ovE9UudFKAmZaXX+o6QED30jF+Dwrv07O2GOnw5rXv1jGQEzoyUP+hqguRGu+8Wmfck8FxKsfNPeUGp8bchSaWJU0S5JJ3TgOYV3oWQ2mXLnB9x/AMl+Q==" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=debug msg="completed challenge" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46:14+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:14 spla-repro go-librespot[18847]: time="2026-08-30T04:46: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 30 04:46:14 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:14 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:15 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:15 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:16 spla-repro dhcpcd[793]: eth0: failed to renew DHCP, rebinding Aug 30 04:46:16 spla-repro dhcpcd[793]: eth0: leased 192.168.200.203 for 300 seconds Aug 30 04:46:16 spla-repro systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 30 04:46:16 spla-repro systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Aug 30 04:46:16 spla-repro systemd[1]: welcome.service: Deactivated successfully. Aug 30 04:46:16 spla-repro systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 30 04:46:16 spla-repro systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 30 04:46:16 spla-repro systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 30 04:46:17 spla-repro welcome[18875]: Resolved ip:[1] 192.168.200.203 Aug 30 04:46:17 spla-repro systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 30 04:46:17 spla-repro systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 30 04:46:17 spla-repro volumio[18538]: info: Received Get System Info Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 04:46:17 spla-repro volumio[18538]: info: Discovery: Getting this device information Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:17 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 04:46:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin bluetooth to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin multiroom to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin metavolumio to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin cd_controller to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 30 04:46:17 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 30 04:46:17 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 30 04:46:17 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:18 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:18 spla-repro go-librespot[18880]: go-librespot daemon starting... Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=debug msg="app state loaded" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:18 spla-repro volumio5-onboarding[21614]: time=2026-08-30T04:46:18.238+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+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 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+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 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+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 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=info msg="zeroconf server listening on port 41031" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=debug msg="obtained new client token: AAGn7KSFNSkaMAzED3BxAj8hsJoJriozFh3RoWtEvZPoHTShYdoiAwfVsMmXEHjnS3l3xl53VDPPY9ot7V0smv1LFfbW7U32b5D6dEOvPVy9YLuyFNosbtpTF6VFLTkvpgczKQlYUzYBYsybcESQFmalTMMhdDrppLm1bXXme3jqYpTm0FVXEDHiN04bj+1rQgRbAtuphiNDb75Tz8Oo2WTD+qBmR/yJMpKy4GyW0PhJSAk/eRPYQIo71w==" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+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 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 30 04:46:18 spla-repro volumio[18538]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 30 04:46:18 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 30 04:46:18 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:18 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:18 spla-repro volumio[18538]: info: Starting MyVolumio Remote Streaming Endpoints Aug 30 04:46:18 spla-repro volumio[18538]: info: MyVolumio login type: Token Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=debug msg="completed challenge" Aug 30 04:46:18 spla-repro volumio[18538]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 30 04:46:18 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46:18+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:18 spla-repro go-librespot[18881]: time="2026-08-30T04:46: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 30 04:46:18 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:18 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:19 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 30 04:46:19 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 30 04:46:19 spla-repro volumio[18538]: info: Streaming services startup Aug 30 04:46:19 spla-repro volumio[18538]: info: Starting Streaming Daemon Aug 30 04:46:19 spla-repro sudo[18905]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:19 spla-repro volumio[18538]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 30 04:46:19 spla-repro sudo[18905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 04:46:19 spla-repro sudo[18905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:19 spla-repro sudo[18905]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:19 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:19 spla-repro volumio[18538]: error: Cannot start Volumio Streaming Daemon Aug 30 04:46:19 spla-repro volumio[18538]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 04:46:19 spla-repro volumio[18538]: sudo: unable to resolve host spla-repro: System error Aug 30 04:46:19 spla-repro volumio[18538]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 04:46:19 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:20 spla-repro volumio[18538]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 30 04:46:20 spla-repro volumio[18538]: info: MyVolumio token set successfully Aug 30 04:46:20 spla-repro volumio[18538]: info: MYVOLUMIO: Adding device Aug 30 04:46:20 spla-repro volumio[18538]: info: MYVOLUMIO: Evaluating Server Aug 30 04:46:21 spla-repro volumio[18538]: info: MyVolumio status changed Aug 30 04:46:21 spla-repro volumio[18538]: info: Streaming services startup Aug 30 04:46:21 spla-repro volumio[18538]: info: Starting Streaming Daemon Aug 30 04:46:21 spla-repro volumio[18538]: info: Removing browser output: myVolumio user plan is not superstar Aug 30 04:46:21 spla-repro volumio[18538]: info: Removing audio output: Aug 30 04:46:21 spla-repro volumio[18538]: info: Stoppping Tunnel 1 Aug 30 04:46:21 spla-repro sudo[18933]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:21 spla-repro sudo[18933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 04:46:21 spla-repro sudo[18933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:21 spla-repro sudo[18933]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:21 spla-repro sudo[18936]: volumio : unable to resolve host spla-repro: System error Aug 30 04:46:21 spla-repro volumio[18538]: error: Cannot start Volumio Streaming Daemon Aug 30 04:46:21 spla-repro volumio[18538]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 04:46:21 spla-repro volumio[18538]: sudo: unable to resolve host spla-repro: System error Aug 30 04:46:21 spla-repro volumio[18538]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 04:46:21 spla-repro sudo[18936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 30 04:46:21 spla-repro sudo[18936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 30 04:46:21 spla-repro sudo[18936]: pam_unix(sudo:session): session closed for user root Aug 30 04:46:21 spla-repro volumio[18538]: info: Remote SSH Stopped Aug 30 04:46:21 spla-repro volumio[18538]: info: Setting Geolocation for MyVolumio to eu6 Aug 30 04:46:21 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:21 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:21 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:21 spla-repro volumio[18538]: info: Successfully Added MyVolumio device Aug 30 04:46:21 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 30 04:46:21 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:22 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:22 spla-repro go-librespot[18938]: go-librespot daemon starting... Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=debug msg="app state loaded" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+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 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+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 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+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 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=info msg="zeroconf server listening on port 45117" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:22 spla-repro volumio[18538]: info: Updating MyVolumio device info Aug 30 04:46:22 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:22 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:22 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=debug msg="obtained new client token: AAEJZ6pC1GI06Vx9VskDkcL37mxPim1sW+NBFt0Yv4oJ8odHCCZ+bWhjSQWqaDtja3WWVeMpf+vwdr6WTZFc/lYWfd8z62spvacv5AmMYok8TRGyC4yhbK9VJWDjmTZFHlWPtG41+vtWOI4DxapN08VlTsrkBoGPhJdkG/81IcouxP3zGANPPZmdWJYBH25ms11JUF/oEfBwMFQWn+ckbuNfNx5lo/YOOE1DB5S+BxGp0hMKdGT5p/dApA==" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=debug msg="completed challenge" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46:22+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:22 spla-repro go-librespot[18939]: time="2026-08-30T04:46: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 30 04:46:22 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:22 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:22 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:22 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:22 spla-repro volumio[18538]: info: Successfully Updated MyVolumio device Aug 30 04:46:23 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:23 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:23 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:23 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:25 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:25 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:25 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 30 04:46:25 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:25 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:25 spla-repro go-librespot[18949]: go-librespot daemon starting... Aug 30 04:46:25 spla-repro go-librespot[18950]: time="2026-08-30T04:46:25+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:25 spla-repro go-librespot[18950]: time="2026-08-30T04:46:25+02:00" level=debug msg="app state loaded" Aug 30 04:46:25 spla-repro go-librespot[18950]: time="2026-08-30T04:46:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46: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-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+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 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+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 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=info msg="zeroconf server listening on port 38607" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=debug msg="obtained new client token: AAF1k/UU/8QbZ4lQOxgnvYSs9QJr+9aB4AWLPsNCHIZYQyBJ+eXy6JbKqZdC5RPGqXwGwTAePUIo8een7xMQ290Qa62ouJvxFtJnfyfDFGnk/HFngtQKCxYL7AjJX0pUeI/+QrlJpCsyExq+hKP/4Jvpy+IFR9CjWC3UC4KWM69yg8gHFzdfFrSiYMGfIU6ov4Pce0Gy191Wzbc7yPb13u+U5ao0W33eK/EU6wB7hoQcuA8ulxH9i6I=" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=debug msg="completed challenge" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:26 spla-repro go-librespot[18950]: time="2026-08-30T04:46:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:26 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:26 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:28 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:28 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:29 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 30 04:46:29 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:29 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:29 spla-repro go-librespot[18973]: go-librespot daemon starting... Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=debug msg="app state loaded" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+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 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+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 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+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 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=info msg="zeroconf server listening on port 35071" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=debug msg="obtained new client token: AAHIXcEaMdribKrUlmdbRJB44HBC2ArOd8TQ29NqWvneO0HB4ivH0IocFRb8uwO9gTz2jJCrY6ZTFnOe7dY64IpI9oZqKT1rFkTWE0yRBXD+r1Bzb8g7IJzPS9UqUEOtln7zY5VhiMgCmpVjXsBSNPOoXOYBrTNGGpzVjwysl3nKjocx5BrSCeKCvbc0rjqa8bpzimJ9X0uWQpd6lCuUCraZDW3ExDO0zI9vmi/923tCl1EK+7DcgqjNWQ==" Aug 30 04:46:29 spla-repro go-librespot[18974]: time="2026-08-30T04:46:29+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:30 spla-repro go-librespot[18974]: time="2026-08-30T04:46:30+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:30 spla-repro go-librespot[18974]: time="2026-08-30T04:46:30+02:00" level=debug msg="completed challenge" Aug 30 04:46:30 spla-repro go-librespot[18974]: time="2026-08-30T04:46:30+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:30 spla-repro go-librespot[18974]: time="2026-08-30T04:46:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:30 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:30 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:31 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:31 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:33 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:33 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:33 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 30 04:46:33 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:33 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:33 spla-repro go-librespot[18984]: go-librespot daemon starting... Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=debug msg="app state loaded" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+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 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+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 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+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 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=info msg="zeroconf server listening on port 41733" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:33 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 04:46:33 spla-repro volumio[18538]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 30 04:46:33 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:33 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=debug msg="obtained new client token: AAFESoOC7fHjUrkGcspJkDxzo9ev+phqEq7NZM4e5r77g4ZAq34P5DuQXq5YHUACRpMqeoYJJ0Az61qri3f9yl/5/HnbAfqwdKfBxoXW0hMpHq2HedaAk5ooxDLlbwaRvHtHb1EzS5sHA+3dSH4uDOjvJixjve8KK5CYBpCaVkgbNNA8nE49Ws82ov6zDmQbFTTn3eOulAeJrLSOMkzyKVUcA7Y8HIFwYlyEknoAi9EOozWrfCdMzetglA==" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+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 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=debug msg="completed challenge" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:33 spla-repro go-librespot[18985]: time="2026-08-30T04:46:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:33 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:33 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:34 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:34 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:35 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 04:46:35 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:35 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 30 04:46:35 spla-repro volumio-remote-updater[725]: Test mode disabled Aug 30 04:46:35 spla-repro volumio-remote-updater[725]: Alpha mode disabled Aug 30 04:46:35 spla-repro volumio-remote-updater[725]: Alpha legacy test mode disabled Aug 30 04:46:35 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 30 04:46:35 spla-repro volumio[18538]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 30 04:46:35 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 30 04:46:36 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 30 04:46:36 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:37 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:37 spla-repro go-librespot[18998]: go-librespot daemon starting... Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=debug msg="app state loaded" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+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 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+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 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+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 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=info msg="zeroconf server listening on port 36145" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=debug msg="obtained new client token: AAGn7JWwsy+R0TDdBGrJh6DE9QQRtQdBJJcn8AatLJWlcW0+dl846EBciTnITOClDyR8tEuBoHpg10y9xkC0d+bT5mxaj2sRVZwRObmcNkkFW3FbTecpjoViqXCkn5JxgUk5vSXP4FDCxY7z3F2WhS4ehHBou+Rl2Ub51O2SNbOV1SOn0j8O9bUFTK3teuYYxl+CfiEKq5GITvIAxhkrvrvMboNcGXu3RTE6eBeSKlt1iz7WFArVGerwAg==" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=debug msg="completed challenge" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:37 spla-repro go-librespot[18999]: time="2026-08-30T04:46:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:37 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:37 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:37 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:37 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetBrowseSources Aug 30 04:46:38 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 04:46:39 spla-repro volumio[18538]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 30 04:46:39 spla-repro volumio[18538]: info: Completed starting MyVolumio Plugin Aug 30 04:46:39 spla-repro volumio[18538]: [Metrics] CommandRouter: 42s 363.22ms Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::volumiosetStartupVolume Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 04:46:39 spla-repro volumio[18538]: info: VolumeController:: Setting startup Volume 45 Aug 30 04:46:39 spla-repro volumio[18538]: info: VolumeController::SetAlsaVolume45 Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::Close All Modals sent Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::Close All Modals sent Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreStateMachine::pushState Aug 30 04:46:39 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 04:46:39 spla-repro volumio[18538]: info: CoreCommandRouter::volumioPushState Aug 30 04:46:40 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 30 04:46:40 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 30 04:46:40 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 30 04:46:40 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 30 04:46:40 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:40 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:40 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:40 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:40 spla-repro go-librespot[19023]: go-librespot daemon starting... Aug 30 04:46:40 spla-repro go-librespot[19024]: time="2026-08-30T04:46:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:40 spla-repro go-librespot[19024]: time="2026-08-30T04:46:40+02:00" level=debug msg="app state loaded" Aug 30 04:46:40 spla-repro go-librespot[19024]: time="2026-08-30T04:46:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46: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 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46: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 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46: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 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=info msg="zeroconf server listening on port 36945" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=debug msg="obtained new client token: AAGA5X5jvPLZuKoBtn4RvmvnyUr3LwI94KNLxRnB79Dp34iCV09WL/WRmS71gQUJdJY0R5dWVh5zGrWzOrv7BPUM/6VvETPvWLrK1ROACCisnKZNeXLfYJqxrfmp04hPEdRASmjVgpAX7lCb/YD3BClNwTbSE3sHw+c7WsF4o1i2215zlvyNOS/kGJ9s+bxiarHhxMGN4DduQNGJqp7hqaQn0yDny2YdveZPssMa3jkoBX8I9B1Qztk=" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=debug msg="completed challenge" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46:41+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:41 spla-repro go-librespot[19024]: time="2026-08-30T04:46: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 30 04:46:41 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:41 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:43 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:43 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:43 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:43 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:46:43 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:43 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:44 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 30 04:46:44 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:44 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:44 spla-repro go-librespot[19036]: go-librespot daemon starting... Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=debug msg="app state loaded" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46: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-gae2.spotify.com:80]" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+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 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+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 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=info msg="zeroconf server listening on port 37699" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=debug msg="obtained new client token: AAFrGO+xf7vu5s2kJyZiRvZys8f/nl1gQ0/1K0MPIndw+1MfTKGj/j4qAkOO8OZD1fvupy5KFnc6FkXz1LgKAPZq6KWfFjW2n/q3HpAnKw5ENn5VYEa6XJKSHE6SvVoYOUuU4l25YGn+F5bFizgtYExD1mHi8FeXnmKQ4Qkc4RvMjVlLNe6MIlW1kpIle6ghSebPqwTEHJN0b259ZBeiuhAntpMYDGaaxONG3R5Hk9Q/4Ps05vp/JyrKmg==" Aug 30 04:46:44 spla-repro go-librespot[19037]: time="2026-08-30T04:46:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:45 spla-repro go-librespot[19037]: time="2026-08-30T04:46:45+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:45 spla-repro go-librespot[19037]: time="2026-08-30T04:46:45+02:00" level=debug msg="completed challenge" Aug 30 04:46:45 spla-repro go-librespot[19037]: time="2026-08-30T04:46:45+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:45 spla-repro go-librespot[19037]: time="2026-08-30T04:46: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 30 04:46:45 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:45 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:46 spla-repro volumio[18538]: info: BOOT COMPLETED Aug 30 04:46:46 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:46 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:48 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 30 04:46:48 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:48 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:48 spla-repro go-librespot[19046]: go-librespot daemon starting... Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=debug msg="app state loaded" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46: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-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+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 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+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 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=info msg="zeroconf server listening on port 45885" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=debug msg="obtained new client token: AAHuveMcD05stfiZCS86vB0bHVcGATD0+3/Sdtd3gGkl24I4KC/6WjR/Ncn35BoeVE8N7vt6tm06BNSaIBBwPu3WA3xNPaHiw55jE+Vfw2EdYmSc/ARSN+Z3Oh0meiPf1D8XaXnpNcXjCzgt0yuLWjyBk2ZANMxohCh0RTXJXfifhrexFkryqgIYva2yT4w/laKuS3HY3Xr5vyEEdJ4wbqpR/343NETQWOk44BWmQZvoIfmBDQdzA+zYSg==" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=debug msg="completed challenge" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46:48+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:48 spla-repro go-librespot[19047]: time="2026-08-30T04:46: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 30 04:46:48 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:48 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:49 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:49 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:51 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 30 04:46:51 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:52 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:52 spla-repro go-librespot[19070]: go-librespot daemon starting... Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=debug msg="app state loaded" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+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 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+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 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+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 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=info msg="zeroconf server listening on port 39203" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=debug msg="obtained new client token: AAFE7u5OLV+RUe8S+GfnCGMhF6ux5ROthYRtSGUjGOXfDjFnnafFA8xw7P4Y2CBJQMKAF4Zrr0mZkEnhWvjPrlq46Dv86T0RATrAgLmgjbuL8LhJdtVUTjjDqLLbRlQt+BY2Nrq3kBtqb8Km8o6eA4v7XFTJW/xQEEMPnsn6gPVI7/9E1rw6hI/FNd5+L2WYnml9QydY9RTS8sHT1q2RaxXf7isYbrZsfvs8dCeua5vRdB2bq2d4LB0cvQ==" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=debug msg="completed challenge" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:52 spla-repro go-librespot[19071]: time="2026-08-30T04:46:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:52 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:52 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:52 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:52 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:53 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:46:53 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:46:55 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 30 04:46:55 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:55 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:55 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:55 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:55 spla-repro go-librespot[19080]: go-librespot daemon starting... Aug 30 04:46:55 spla-repro go-librespot[19081]: time="2026-08-30T04:46:55+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:55 spla-repro go-librespot[19081]: time="2026-08-30T04:46:55+02:00" level=debug msg="app state loaded" Aug 30 04:46:55 spla-repro go-librespot[19081]: time="2026-08-30T04:46:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+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 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+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 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+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 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=info msg="zeroconf server listening on port 35605" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=debug msg="obtained new client token: AAEG04Fs2lVdJdsxYXXDfBm2D2GGUq1/Gxcq9BvJUuIO3USJdimp99yWZA1WfQYbkueStTL5RuZrh8QlosFLAKA2XDXpmYvqS06EIZbsmHRnCxuN5xKVaeM+b8MdO5cy6qDTwrLD41F3VRvYBhc0FbwlfbxwzEMZgx+etCNsXYnRJAYwiluXAzNRsALlXGkWqbUuJXPJU9N2+gFX8zB/Sb1ijk1aSPaRwzbrZQBpgiXOP/P18DL0krU=" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=debug msg="completed keyexchange" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=debug msg="completed challenge" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:46:56 spla-repro go-librespot[19081]: time="2026-08-30T04:46:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:46:56 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:46:56 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:46:58 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:46:58 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:46:59 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 30 04:46:59 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:59 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:46:59 spla-repro go-librespot[19090]: go-librespot daemon starting... Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=debug msg="app state loaded" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+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 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+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 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+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 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=info msg="zeroconf server listening on port 35055" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=debug msg="obtained new client token: AAGCzqNCHx7vzacnKWeErzhbbT4zTXWGtwQ21mrxzwg3IHcritozLX9AIh6qXDyez1PdgK5q2C97AAqQanHwzDYgu7avCwsrr/zLB7juR48UV+iNDlq7iGxz/I0x+UqlUQ4ABBfggAcE5cCjK7nfIlXPwD2MaKd+0fq9AXYd+ErOfEAnRYLr/REdaatJI6HytdwRUV1/87U62DWUPu41P0Hc+d+hNUfebPTbQUyUNaT9JSztDD/d4cgufQ==" Aug 30 04:46:59 spla-repro go-librespot[19105]: time="2026-08-30T04:46:59+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:00 spla-repro go-librespot[19105]: time="2026-08-30T04:47:00+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:00 spla-repro go-librespot[19105]: time="2026-08-30T04:47:00+02:00" level=debug msg="completed challenge" Aug 30 04:47:00 spla-repro go-librespot[19105]: time="2026-08-30T04:47:00+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:00 spla-repro go-librespot[19105]: time="2026-08-30T04:47:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:00 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:00 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:01 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:01 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:03 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:47:03 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:47:03 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:47:03 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:47:03 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 30 04:47:03 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:03 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:03 spla-repro go-librespot[19114]: go-librespot daemon starting... Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=debug msg="app state loaded" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+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 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+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 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+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 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=info msg="zeroconf server listening on port 41929" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=debug msg="obtained new client token: AAHqp40zhb0LpeU9jKIzJYGaMvv6JyzCQn3vJdF6TxZd+DUj0fXIS/PHMAoUgdsbFYwmG8Q26mdrEGhi2inFEhU+aXHtMD1MGH7zWZQPg3hOLEu+s44dCaE3iOMO7JUpVMOrgyarnm5xUfuLMI2MrpivgyOMdp2fO5igpsanTB7ZxjE2t3uhEl0vYZ4XnQibCwPhY73JdsaqiiGrfo0jl5ptbviuiNLups0z1lksYizyFxKMjgY2Dzcnag==" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=debug msg="completed challenge" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:03 spla-repro go-librespot[19115]: time="2026-08-30T04:47:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:03 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:03 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:04 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:04 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:06 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 30 04:47:06 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:07 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:07 spla-repro go-librespot[19126]: go-librespot daemon starting... Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=debug msg="app state loaded" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+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 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+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 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+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 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=info msg="zeroconf server listening on port 46169" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=debug msg="obtained new client token: AAGq0TSxEJhV3t5BB+sqJu35rMS7UZ64rehKLR/LzFP9NV+khEuZRDtW/euCodzVivHjHcB9xNwiKVZFi6bJVd0RcJ0iQOL77MeuDHfzozydPJEtW4d+o7vOGCpeI1m/jdT/oX2NPgaMNLuWy0anSh0lJQA7yD4as4Jer+JRZDA991+6sdC9JOSbG9Rv52eL2pPMfMELYwIm5mxSCnZkFn06YU+lS/jKNhy1ADLymMPClyDSfGmPtuWJ+Q==" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=debug msg="completed challenge" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:07 spla-repro go-librespot[19127]: time="2026-08-30T04:47:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:07 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:07 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:07 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:07 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:10 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 30 04:47:10 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:10 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:10 spla-repro go-librespot[19150]: go-librespot daemon starting... Aug 30 04:47:10 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:10 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:10 spla-repro go-librespot[19151]: time="2026-08-30T04:47:10+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:10 spla-repro go-librespot[19151]: time="2026-08-30T04:47:10+02:00" level=debug msg="app state loaded" Aug 30 04:47:10 spla-repro go-librespot[19151]: time="2026-08-30T04:47:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+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 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+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 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+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 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=info msg="zeroconf server listening on port 41169" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=debug msg="obtained new client token: AAEqOBxXXarrM2zkHjTpRisvFYfV9FFpK476c0pMD8v9r+76a9JDTkp0EkIrXGLkS1tMKFClCVp1WxyFwQohj+EIhDzebgyMWxp4Nss3NGif+I9vD5bGgEdD3coIdqj29+PB3sOjC/++xxqeIk9yOf+C1EeqodhT0pvLbcKzaAx+qD/AmsSMa1mADSYNnh3z/sV6Csn083VmRjHsqnCWSreXzEDLISYaKwVr6EDzgEQBbjF75HESZOg=" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=debug msg="completed challenge" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:11 spla-repro go-librespot[19151]: time="2026-08-30T04:47:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:11 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:11 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:13 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:47:13 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:47:13 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:13 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:14 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 30 04:47:14 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:14 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:14 spla-repro go-librespot[19160]: go-librespot daemon starting... Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=debug msg="app state loaded" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47: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-gew4.spotify.com:80]" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+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 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+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 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=info msg="zeroconf server listening on port 43767" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=debug msg="obtained new client token: AAGW40pz4s74/WuDDg7hzzGn9Gszp947pNjCWXciBkRNjh6bhBGX7DC+y4w6Ynbw+7BWYp2grjRNhkcDkv2W7O5GCFFeDmwcnI7324W7UqMQPd5rKPI6ZvmCH7uIzePJNCPzGKB2grqAe6lYzfOnzXvkpJqPhsypVLjc4MALUZlysyixouqV9RihNQCo993S8X/nKFweSX3APU2xzGUSlU4YQyrJdjWbwvVQMkVImM9JM1D+nXmQUDGptA==" Aug 30 04:47:14 spla-repro go-librespot[19161]: time="2026-08-30T04:47:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:15 spla-repro go-librespot[19161]: time="2026-08-30T04:47:15+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:15 spla-repro go-librespot[19161]: time="2026-08-30T04:47:15+02:00" level=debug msg="completed challenge" Aug 30 04:47:15 spla-repro go-librespot[19161]: time="2026-08-30T04:47:15+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:15 spla-repro go-librespot[19161]: time="2026-08-30T04:47:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:15 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:15 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:16 spla-repro systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 30 04:47:16 spla-repro systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Aug 30 04:47:16 spla-repro systemd[1]: welcome.service: Deactivated successfully. Aug 30 04:47:16 spla-repro systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 30 04:47:16 spla-repro systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 30 04:47:16 spla-repro systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 30 04:47:16 spla-repro welcome[19188]: Resolved ip:[1] 192.168.200.203 Aug 30 04:47:16 spla-repro systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 30 04:47:16 spla-repro systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 30 04:47:16 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:16 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:17 spla-repro volumio[18538]: info: Received Get System Info Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 04:47:17 spla-repro volumio[18538]: info: Discovery: Getting this device information Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:47:17 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 04:47:17 spla-repro volumio[18538]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 04:47:18 spla-repro volumio5-onboarding[21614]: time=2026-08-30T04:47:18.001+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 04:47:18 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 30 04:47:18 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:18 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:18 spla-repro go-librespot[19193]: go-librespot daemon starting... Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=debug msg="app state loaded" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+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 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+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 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+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 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=info msg="zeroconf server listening on port 42365" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=debug msg="obtained new client token: AAG2ZQGIOf5Tk5yNr4U/mJX8fCtpIlHAr+V3+Yg6yCuJTc9XFWialskCIMt70rx+8rvdJCCOPTAQjN969tVktFIEDuSDSnn+dyng7cMH0hb1OprNV6GUOP4+qv4SJi0SUT3eKXStrHUohdnwPv4uJW/6bPGs19swFCrpNQ7kDyF7cYy1+88EQQ0p9Uy7im14P+Fc3pxx7g/h4A9dcfKjfZ1e4ce98PoqZZ8aK5/T9e39vcdvzVK3ASeOdQ==" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=debug msg="completed challenge" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47:18+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:18 spla-repro go-librespot[19194]: time="2026-08-30T04:47: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 30 04:47:18 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:18 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:19 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:19 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:21 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 30 04:47:21 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:22 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:22 spla-repro go-librespot[19217]: go-librespot daemon starting... Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=debug msg="app state loaded" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+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 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+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 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+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 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=info msg="zeroconf server listening on port 34607" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=debug msg="obtained new client token: AAEUXQ1vbV0W4HrcxXQN2JqYw+gxUEWqXcPENUMOsLv67aO1awiEteaqPMFkiMkowS21WZjzJc133XwgAVrNLhvFOQKT5mVIYLd7jQAtv0pbIvqoIv1sR6LCX1Fti6BjDXysb99i+x8fkYmG8SrydgYJTMmggdKXnmhBv1dUvmlNM1Mr4vig3WgpgS1+UxQkSpvfu+IoeO+s7gl3MdBRiYFohJk6iZAeDRmsCPtQqnbsERRqWfC77SNe/g==" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=debug msg="completed challenge" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47:22+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:22 spla-repro go-librespot[19218]: time="2026-08-30T04:47: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 30 04:47:22 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:22 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:22 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:22 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:23 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:47:23 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:47:23 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:47:23 spla-repro volumio[18538]: info: Listing playlists Aug 30 04:47:25 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:25 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:25 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 30 04:47:25 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:26 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:26 spla-repro go-librespot[19228]: go-librespot daemon starting... Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=debug msg="app state loaded" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+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 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+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 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=info msg="zeroconf server listening on port 46555" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=debug msg="obtained new client token: AAGCd7SfCIOQLqOYkGUeo8WeYpIk5YiuWNLgXNIYOZLhwBeliB9eUXfx2O24TS++yxJR1FWGjX1/Z/xsDy5G4V+bHU/NObs6frXy4EZBAH1GGHz9+eoKoyf6GMnwB4HNeTe6mPojgvpD7sjfQq4f31qSBZr6GyDlh2dWmClCsZJmJpS8wD5wSshsHTeiGSn6WG8xisrBiBcVyhLZdY2/rQWrgw41E9Cc6Jc269R80LdCDo1LMkBeGgh3sg==" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=debug msg="completed challenge" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:26 spla-repro go-librespot[19229]: time="2026-08-30T04:47:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:26 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:26 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:28 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:28 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:29 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 30 04:47:29 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:29 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:29 spla-repro go-librespot[19252]: go-librespot daemon starting... Aug 30 04:47:29 spla-repro go-librespot[19253]: time="2026-08-30T04:47:29+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:29 spla-repro go-librespot[19253]: time="2026-08-30T04:47:29+02:00" level=debug msg="app state loaded" Aug 30 04:47:29 spla-repro go-librespot[19253]: time="2026-08-30T04:47:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+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 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+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 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+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 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=info msg="zeroconf server listening on port 40093" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=debug msg="obtained new client token: AAGjc3Ps3gVhFcxkKtL8zP1U5KVUfqBm317amTMT6fVcA61XpHeye1hxWwJFlA7JyXh38idj/bWj7RYZ3mnNF4cd2E+lIYi4y6+0IV+qVC+ewT+U6KXr3Bvyv7dm9cuPmgdnxH8d2IiDfZ/mEE20TflJ/DWnZ4VS53Fd9sFU3bx7ZLtBM3cFvDqWtxtqx4ybIdJMdKx0ZpNjjfj6th//SyqTS3sdMn0kPzHKPO2bulJPKeWFq5AM7zY=" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=debug msg="completed challenge" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:30 spla-repro go-librespot[19253]: time="2026-08-30T04:47:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:30 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:30 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:31 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:31 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:33 spla-repro volumio[18538]: info: CoreCommandRouter::volumioGetState Aug 30 04:47:33 spla-repro volumio[18538]: info: CorePlayQueue::getTrack 0 Aug 30 04:47:33 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 30 04:47:33 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:33 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:33 spla-repro go-librespot[19262]: go-librespot daemon starting... Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=debug msg="app state loaded" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+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 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+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 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+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 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=info msg="zeroconf server listening on port 37675" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=debug msg="obtained new client token: AAG1e1iKooa3ykGibeqFA1Q0IvLt9y1h9kxFCbq+0hQZRZWI+yaXRJSQw8I4b5qwCeUYzmeaEDMELOln9Ob0pNjUt5PNiBuH2oM9Wlwah4tw734B/lNLbt7dRJsvP3RKu3NayF9GMl7QLH8xGj0DKcFtppWwXCngO1LGGxtiAtTXPaUvv8REcqgauuzf4SnV2b1dALIPAkivE/uD2G1+LCjK2pjGpu7MawK09hqulb9GGmanPqIYQWftFg==" Aug 30 04:47:33 spla-repro go-librespot[19263]: time="2026-08-30T04:47:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:34 spla-repro go-librespot[19263]: time="2026-08-30T04:47:34+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:34 spla-repro go-librespot[19263]: time="2026-08-30T04:47:34+02:00" level=debug msg="completed challenge" Aug 30 04:47:34 spla-repro go-librespot[19263]: time="2026-08-30T04:47:34+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:34 spla-repro go-librespot[19263]: time="2026-08-30T04:47:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:34 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:34 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:34 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:34 spla-repro volumio[18538]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:37 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 30 04:47:37 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:37 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:37 spla-repro go-librespot[19273]: go-librespot daemon starting... Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="app state loaded" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+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 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+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 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+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 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=info msg="zeroconf server listening on port 36185" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="obtained new client token: AAGcPgoRmf/6ZS2Gzz9Ugopn6QieMDpQBIj0/T4ezkYleotZoBGpVFAOJWIxv1wSS/z8k1drA1LuanFu7oVxjhPDEdF+Ymd9NI9nilbqGVYLf5rROGYbS8904w46OyoHl/VB+x84j1BfYHEiVqWietLbcKg2hr6gIiErLDZVYw2Olb4bhxUJdTXhikXHaBhvAHFeU09PajK8DPBhw9em5vwhsIBRIBamwWtthEab7MLs0vv3lOMejDFgxQ==" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="completed challenge" Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:37 spla-repro volumio[18538]: info: Initializing connection to go-librespot Websocket Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=debug msg="new websocket client" Aug 30 04:47:37 spla-repro volumio[18538]: info: Connection to go-librespot Websocket established Aug 30 04:47:37 spla-repro go-librespot[19274]: time="2026-08-30T04:47:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 04:47:37 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:37 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 04:47:37 spla-repro volumio[18538]: info: Connection to go-librespot Websocket closed Aug 30 04:47:40 spla-repro volumio[18538]: info: Getting Spotify volume Aug 30 04:47:40 spla-repro volumio[18538]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 04:47:40 spla-repro volumio[18538]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 04:47:40 spla-repro volumio[18538]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 30 04:47:40 spla-repro volumio[18538]: errno: -111, Aug 30 04:47:40 spla-repro volumio[18538]: code: 'ECONNREFUSED', Aug 30 04:47:40 spla-repro volumio[18538]: syscall: 'connect', Aug 30 04:47:40 spla-repro volumio[18538]: address: '127.0.0.1', Aug 30 04:47:40 spla-repro volumio[18538]: port: 9879, Aug 30 04:47:40 spla-repro volumio[18538]: response: undefined Aug 30 04:47:40 spla-repro volumio[18538]: } Aug 30 04:47:40 spla-repro volumio[18538]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 04:47:40 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 30 04:47:40 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:41 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 04:47:41 spla-repro go-librespot[19308]: go-librespot daemon starting... Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=debug msg="app state loaded" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+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 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+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 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=info msg="zeroconf server listening on port 40141" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=debug msg="obtained new client token: AAEWXykq+/v31VbUduuknOEOjRUvNajogaukZy/C5QHt6Jqa3NDxSJ+535ixekYCmhSRLZfUdNV6moL3V63cR0COgkga9cdRlDg9Q1u8p+bG2F9uAg97WJpjRfSVPy1yAvRVnjHryjrEiW+82si1d3SXXD6Pxn8AlrasYfPesjEEm/VGLLea5MtETWpNQTKGKPuUrD78qnLnC4Ebz1kCSfFulTDEEAfntDGhyIoENKODs6KG61KrvIJgig==" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=debug msg="completed keyexchange" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=debug msg="completed challenge" Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47:41+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 30 04:47:41 spla-repro sudo[19321]: volumio : unable to resolve host spla-repro: System error Aug 30 04:47:41 spla-repro sudo[19321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 04:46' Aug 30 04:47:41 spla-repro sudo[19321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 04:47:41 spla-repro go-librespot[19310]: time="2026-08-30T04:47: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 30 04:47:41 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 04:47:41 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"