Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=debug msg="obtained new client token: AAF9KFKxZVZ6Y454fm8rhf4PUPbV7uoLtPjK/QNpaqUCrGFaaPV0NaYcWdu8dKmAvxDw0KbRRtgQfCSgi3A0hLqA+3IFBd8TE4FTTnDRNd+JIwJ6FeRtzG0E0hMP8cQLMiKlgsTNC3+NVMzDtLiurLGa9ip4/hY+fRJI1gqx0tmVb+G2Zm2c8eOjvpIe76MhvM5v9AfFbTft3K5tQaV656PMfuZ4P009SkpC/8Iiiopkfy4mU6U+XZQ=" Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=debug msg="completed challenge" Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:00 spla-repro go-librespot[5656]: time="2026-09-01T03:59:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:00 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:00 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:00 spla-repro volumio[5640]: info: MYVOLUMIO Environment detected Sep 01 03:59:00 spla-repro volumio[5640]: info: Plugin folders cleanup Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning into folder /volumio/app/plugins/ Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category audio_interface Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category miscellanea Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category music_service Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category plugins.json Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category system_controller Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category user_interface Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning into folder /data/plugins/ Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category audio_interface Sep 01 03:59:00 spla-repro volumio[5640]: info: Scanning category music_service Sep 01 03:59:00 spla-repro volumio[5640]: info: Plugin folders cleanup completed Sep 01 03:59:00 spla-repro volumio[5640]: info: ------------------------------------------- Sep 01 03:59:00 spla-repro volumio[5640]: info: ----- Core plugins startup ---- Sep 01 03:59:00 spla-repro volumio[5640]: info: ------------------------------------------- Sep 01 03:59:00 spla-repro volumio[5640]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 03:59:00 spla-repro volumio[5640]: info: Adding plugin upnp to MyMusic Plugins Sep 01 03:59:00 spla-repro volumio[5640]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 03:59:00 spla-repro volumio[5640]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 03:59:00 spla-repro volumio[5640]: info: Loading plugins from folder /data/plugins/ Sep 01 03:59:00 spla-repro volumio[5640]: info: Loading plugin "system"... Sep 01 03:59:00 spla-repro volumio[5640]: info: Loading plugin "appearance"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "network"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Refreshing Cached IP Addresses Sep 01 03:59:01 spla-repro sudo[5678]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:01 spla-repro sudo[5680]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:01 spla-repro sudo[5678]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 03:59:01 spla-repro sudo[5678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:01 spla-repro sudo[5680]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "services"... Sep 01 03:59:01 spla-repro sudo[5680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:01 spla-repro sudo[5678]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "volumio5onboarding"... Sep 01 03:59:01 spla-repro sudo[5680]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:01 spla-repro sudo[5687]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:01 spla-repro sudo[5687]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 03:59:01 spla-repro sudo[5687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "alsa_controller"... Sep 01 03:59:01 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "wizard"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "networkfs"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Starting Udev Watcher for removable devices Sep 01 03:59:01 spla-repro volumio[5640]: info: Ignoring mount for partition: boot Sep 01 03:59:01 spla-repro volumio[5640]: info: Ignoring mount for partition: volumio Sep 01 03:59:01 spla-repro volumio[5640]: info: Ignoring mount for partition: volumio_data Sep 01 03:59:01 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "volumio_command_line_client"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "upnp"... Sep 01 03:59:01 spla-repro volumio[5640]: info: [1788227941972] Starting Upmpd Daemon Sep 01 03:59:01 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "my_music"... Sep 01 03:59:01 spla-repro volumio[5640]: info: Loading plugin "mpd"... Sep 01 03:59:02 spla-repro volumio[5640]: info: Loading plugin "upnp_browser"... Sep 01 03:59:02 spla-repro volumio-remote-updater[725]: [2026-09-01 03:59:02] [connect] Successful connection Sep 01 03:59:02 spla-repro sudo[5687]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:03 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 03:59:03 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:03 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:03 spla-repro go-librespot[5711]: go-librespot daemon starting... Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+02:00" level=debug msg="app state loaded" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+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]" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+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]" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+02:00" level=info msg="zeroconf server listening on port 37403" Sep 01 03:59:03 spla-repro go-librespot[5712]: time="2026-09-01T03:59:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:03 spla-repro volumio[5640]: info: Starting UPNP Browser Sep 01 03:59:03 spla-repro volumio[5640]: info: Loading plugin "alarm-clock"... Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=debug msg="obtained new client token: AAH7xplJdMKQz4b0QHNfOGkJhVggQEr8xJLixjHxAUDvFDVepakMWQS9hb7JhOkiqIpk2HLPp/xGdUB4o7LKnTDK49iGUJph0e6pjz3PwRZeK1Lz+0L5EGj7VBf2wnEXdeIIIL/rbIx4D9GPOCf5w19DD/h0VghXWeyWLtu1YT0mBZ4PVVBRJ5fVj2/9s5XNVK4WhxRe9G0MMGE/KoPUa3liVQwQ5lBvCy1hMnUqDn+wfs7YKDOQ9Iz3VA==" Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "airplay_emulation"... Sep 01 03:59:04 spla-repro volumio[5640]: info: Starting Shairport Sync Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=debug msg="completed challenge" Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "last_100"... Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "webradio"... Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "i2s_dacs"... Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "volumiodiscovery"... Sep 01 03:59:04 spla-repro go-librespot[5712]: time="2026-09-01T03:59:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:04 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:04 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** For more information see Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 03:59:04 spla-repro volumio[5640]: *** WARNING *** For more information see Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** For more information see Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 03:59:04 spla-repro node[5640]: *** WARNING *** For more information see Sep 01 03:59:04 spla-repro volumio[5640]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 03:59:04 spla-repro volumio[5640]: info: Discovery: Started advertising with name: Spálňa-repro Sep 01 03:59:04 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 03:59:04 spla-repro volumio[5640]: info: Loading plugin "spop"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "outputs"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "albumart"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Plugin example_plugin is not enabled Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "inputs"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "updater_comm"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Plugin mpdemulation is not enabled Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "rest_api"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading plugin "websocket"... Sep 01 03:59:05 spla-repro volumio[5640]: info: Starting Socket.io Server version 1.7.4 Sep 01 03:59:05 spla-repro volumio[5640]: info: Plugin fusiondsp is not enabled Sep 01 03:59:05 spla-repro volumio[5640]: info: Loading i18n strings for locale sk Sep 01 03:59:05 spla-repro volumio[5640]: Updating browse sources language Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::initPlayerControls Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 03:59:05 spla-repro volumio[5640]: Express server listening on port 3000 Sep 01 03:59:05 spla-repro volumio[5640]: [Metrics] WebUI: 6s 547.41ms Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreStateMachine::resetVolumioState Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreStateMachine::getcurrentVolume Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 03:59:05 spla-repro volumio[5640]: info: Cannot read play queue from file Sep 01 03:59:05 spla-repro volumio[5640]: info: Volumio Network Manager: Network status updated: 1 Sep 01 03:59:05 spla-repro volumio[5640]: Unable to parse: Sep 01 03:59:05 spla-repro volumio[5640]: Simple mixer control 'Master',0 Sep 01 03:59:05 spla-repro volumio[5640]: Capabilities: volume volume-joined Sep 01 03:59:05 spla-repro volumio[5640]: Playback channels: Mono Sep 01 03:59:05 spla-repro volumio[5640]: Capture channels: Mono Sep 01 03:59:05 spla-repro volumio[5640]: Limits: 0 - 248 Sep 01 03:59:05 spla-repro volumio[5640]: Mono: 112 [45%] Sep 01 03:59:05 spla-repro volumio[5640]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 03:59:05 spla-repro volumio[5640]: 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 Sep 01 03:59:05 spla-repro volumio[5723]: Forking 3 albumart workers Sep 01 03:59:05 spla-repro volumio[5640]: 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 Sep 01 03:59:05 spla-repro volumio[5640]: info: Received Get System Info Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 03:59:05 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: Getting this device information Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 03:59:06 spla-repro volumio[5640]: 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: 2 Sep 01 03:59:06 spla-repro volumio[5640]: Unable to parse: Sep 01 03:59:06 spla-repro volumio[5640]: Simple mixer control 'Master',0 Sep 01 03:59:06 spla-repro volumio[5640]: Capabilities: volume volume-joined Sep 01 03:59:06 spla-repro volumio[5640]: Playback channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Capture channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Limits: 0 - 248 Sep 01 03:59:06 spla-repro volumio[5640]: Mono: 112 [45%] Sep 01 03:59:06 spla-repro volumio[5640]: info: VolumeController:: Volume=undefined Mute =false Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::pushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioPushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::updateTrackBlock Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrackBlock Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 03:59:06 spla-repro volumio[5640]: 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: 3 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::setRepeat null single undefined Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::pushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioPushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::setRandom null Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::pushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioPushState Sep 01 03:59:06 spla-repro volumio[5640]: info: Setting Device type: Raspberry PI Sep 01 03:59:06 spla-repro volumio-remote-updater[725]: [2026-09-01 03:59:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788227942 101 Sep 01 03:59:06 spla-repro volumio[5640]: 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: 4 Sep 01 03:59:06 spla-repro volumio[5640]: info: Completed loading Core Plugins Sep 01 03:59:06 spla-repro volumio[5640]: info: Preparing to generate the ALSA configuration file Sep 01 03:59:06 spla-repro volumio[5640]: Unable to parse: Sep 01 03:59:06 spla-repro volumio[5640]: Simple mixer control 'Master',0 Sep 01 03:59:06 spla-repro volumio[5640]: Capabilities: volume volume-joined Sep 01 03:59:06 spla-repro volumio[5640]: Playback channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Capture channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Limits: 0 - 248 Sep 01 03:59:06 spla-repro volumio[5640]: Mono: 112 [45%] Sep 01 03:59:06 spla-repro volumio[5640]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: 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 Sep 01 03:59:06 spla-repro volumio[5640]: Unable to parse: Sep 01 03:59:06 spla-repro volumio[5640]: Simple mixer control 'Master',0 Sep 01 03:59:06 spla-repro volumio[5640]: Capabilities: volume volume-joined Sep 01 03:59:06 spla-repro volumio[5640]: Playback channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Capture channels: Mono Sep 01 03:59:06 spla-repro volumio[5640]: Limits: 0 - 248 Sep 01 03:59:06 spla-repro volumio[5640]: Mono: 112 [45%] Sep 01 03:59:06 spla-repro volumio[5640]: info: VolumeController:: Volume=undefined Mute =false Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreStateMachine::pushState Sep 01 03:59:06 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioPushState Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: adding 284e4a17-0388-4ad0-8157-75a8b67cae8e Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: Found device kupelna-repro Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: Connecting to remote: 192.168.200.202 Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: adding d4caa6fc-95c1-41bd-89e0-c640d24940c4 Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: Found device kuchyna-repro Sep 01 03:59:06 spla-repro volumio[5640]: info: Discovery: Connecting to remote: 192.168.200.201 Sep 01 03:59:06 spla-repro volumio[5640]: 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 Sep 01 03:59:06 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:06 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:06 spla-repro volumio[5640]: info: Asound.conf file unchanged, so no further update is needed Sep 01 03:59:06 spla-repro volumio[5640]: info: Output device has changed, restarting MPD Sep 01 03:59:06 spla-repro volumio[5640]: info: Output device has changed, restarting Shairport Sync Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:06 spla-repro sudo[5780]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:06 spla-repro volumio[5640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 03:59:06 spla-repro volumio[5640]: info: ___________ START PLUGINS ___________ Sep 01 03:59:06 spla-repro sudo[5780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 03:59:06 spla-repro sudo[5780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:06 spla-repro sudo[5780]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:06 spla-repro volumio[5640]: info: ControllerMpd::onStart: Initializing MPD Sep 01 03:59:06 spla-repro volumio[5640]: info: Creating MPD Configuration file Sep 01 03:59:06 spla-repro sudo[5782]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:06 spla-repro sudo[5789]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:06 spla-repro sudo[5782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 03:59:06 spla-repro sudo[5782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:06 spla-repro sudo[5789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Sep 01 03:59:06 spla-repro sudo[5789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 03:59:06 spla-repro volumio[5640]: info: [1788227946750] CoreMusicLibrary::Adding element Mediálne servery Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 03:59:06 spla-repro sudo[5795]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:06 spla-repro sudo[5791]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:06 spla-repro sudo[5795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 03:59:06 spla-repro sudo[5795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:06 spla-repro volumio[5640]: info: UPNP Browser: Client initialized successfully Sep 01 03:59:06 spla-repro sudo[5791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 03:59:06 spla-repro sudo[5791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:06 spla-repro sudo[5791]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:06 spla-repro systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 03:59:06 spla-repro sudo[5789]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:06 spla-repro systemd[1]: mpd.service: Deactivated successfully. Sep 01 03:59:06 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 03:59:06 spla-repro systemd[1]: mpd.service: Consumed 5.664s CPU time. Sep 01 03:59:06 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Sep 01 03:59:06 spla-repro volumio[5640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 03:59:06 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 03:59:06 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:06 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:07 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 03:59:07 spla-repro volumio[5640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 03:59:07 spla-repro volumio[5640]: info: [1788227947029] CoreMusicLibrary::Adding element Last_100 Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 03:59:07 spla-repro volumio[5640]: info: [1788227947034] CoreMusicLibrary::Adding element Webradio Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 03:59:07 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 03:59:07 spla-repro volumio5-onboarding[4505]: time=2026-09-01T03:59:07.051+02:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 03:59:07 spla-repro volumio[5640]: info: Initializing BBC Radios Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:07 spla-repro volumio[5640]: info: Creating Spotify config file Sep 01 03:59:07 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:07 spla-repro sudo[5808]: root : unable to resolve host spla-repro: System error Sep 01 03:59:07 spla-repro sudo[5808]: sudo: unable to resolve host spla-repro: System error Sep 01 03:59:07 spla-repro sudo[5808]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 03:59:07 spla-repro sudo[5808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 03:59:07 spla-repro sudo[5808]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:07 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 01 03:59:07 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:07 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:07 spla-repro go-librespot[5824]: go-librespot daemon starting... Sep 01 03:59:07 spla-repro go-librespot[5825]: time="2026-09-01T03:59:07+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:07 spla-repro go-librespot[5825]: time="2026-09-01T03:59:07+02:00" level=info msg="zeroconf server listening on port 42355" Sep 01 03:59:07 spla-repro go-librespot[5825]: time="2026-09-01T03:59:07+02:00" level=info msg="using built-in mDNS responder" Sep 01 03:59:07 spla-repro volumio[5740]: Starting albumart workers Sep 01 03:59:07 spla-repro volumio[5640]: info: Volumio Calling Home Sep 01 03:59:08 spla-repro volumio[5742]: Starting albumart workers Sep 01 03:59:08 spla-repro volumio[5741]: Starting albumart workers Sep 01 03:59:08 spla-repro volumio[5640]: info: Discovery: adding e4ea6882-b508-4641-a5d5-383d83cd05b4 Sep 01 03:59:08 spla-repro volumio[5640]: info: Discovery: Found device Spálňa-repro Sep 01 03:59:08 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:08 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:08 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 01 03:59:08 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:08 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:08 spla-repro volumio[5640]: info: Discovery: this is already registered, e4ea6882-b508-4641-a5d5-383d83cd05b4 Sep 01 03:59:08 spla-repro volumio[5640]: info: Discovery: Found device Spálňa-repro Sep 01 03:59:08 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:08 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:08 spla-repro volumio[5640]: info: MPD Permissions set Sep 01 03:59:08 spla-repro volumio[5640]: info: MPD Permissions set Sep 01 03:59:08 spla-repro volumio[5640]: info: Discovery: Connected to remote: 192.168.200.202 Sep 01 03:59:09 spla-repro volumio[5640]: info: Volumio called home Sep 01 03:59:09 spla-repro volumio[5640]: info: Spotify config file written Sep 01 03:59:09 spla-repro sudo[5844]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:09 spla-repro sudo[5844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 03:59:09 spla-repro sudo[5844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:09 spla-repro systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 03:59:09 spla-repro systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 03:59:09 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:09 spla-repro volumio[5640]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 01 03:59:09 spla-repro volumio[5640]: info: Discovery: Connected to remote: 192.168.200.201 Sep 01 03:59:09 spla-repro go-librespot[5858]: go-librespot daemon starting... Sep 01 03:59:09 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:09 spla-repro sudo[5844]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="app state loaded" Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:09 spla-repro volumio[5640]: info: No need to fix Spotify hosts Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 01 03:59:09 spla-repro volumio[5640]: info: An error occurred while refreshing Spotify Token Error: Bad Request Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:09 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:09 spla-repro volumio[5640]: info: Starting Shairport Sync Sep 01 03:59:09 spla-repro volumio[5640]: info: Starting Shairport Sync Sep 01 03:59:09 spla-repro volumio[5640]: info: Starting Shairport Sync Sep 01 03:59:09 spla-repro sudo[5879]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:09 spla-repro sudo[5879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 03:59:09 spla-repro sudo[5879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:09 spla-repro sudo[5884]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:09 spla-repro sudo[5884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 03:59:09 spla-repro sudo[5884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:09 spla-repro sudo[5882]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:09 spla-repro sudo[5882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 03:59:09 spla-repro sudo[5882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:09 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 03:59:09 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 03:59:09 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 03:59:09 spla-repro systemd[1]: shairport-sync.service: Consumed 3.998s CPU time. Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=info msg="zeroconf server listening on port 46511" Sep 01 03:59:09 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:09 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:09 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 03:59:09 spla-repro sudo[5879]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:09 spla-repro sudo[5884]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:09 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 03:59:09 spla-repro volumio[5640]: info: Shairport-Sync Started Sep 01 03:59:09 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 03:59:09 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 03:59:09 spla-repro volumio[5640]: Error adding Membership: Error: addMembership EINVAL Sep 01 03:59:09 spla-repro volumio[5640]: info: Shairport-Sync Started Sep 01 03:59:09 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 03:59:09 spla-repro sudo[5882]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:09 spla-repro volumio[5640]: info: Shairport-Sync Started Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="obtained new client token: AAHCEj32dn037QZ18CS1Lk+xymFygbq0AgY6ZalC5iwbkkIwX4lbXuUY5xL2Pv7BRx7+8pKe4oTF8jUO0n0lLt5Qhybanr/22+JA4uR0ElWMVC9dLgmvP6p7tP+vYJd3VQezBr0X2Trq2fr0JG9pt+VIZyKhcgTme95tL1E01D7falj0SKcWMZlTgQLX7mONCyPHnPP3OBkJ6ZCBK+NnM+N8omrGj7GfTvRYimvZXz5ZUYqJNJKyBQAr8A==" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=debug msg="completed challenge" Sep 01 03:59:09 spla-repro go-librespot[5860]: time="2026-09-01T03:59:09+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:10 spla-repro go-librespot[5860]: time="2026-09-01T03:59:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:10 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:10 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:11 spla-repro mpd[5823]: 2026-09-01T03:59:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 03:59:11 spla-repro systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 03:59:11 spla-repro sudo[5782]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:11 spla-repro sudo[5795]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:11 spla-repro volumio[5640]: info: Completed starting Core Plugins Sep 01 03:59:11 spla-repro volumio[5640]: info: ------------------------------------------- Sep 01 03:59:11 spla-repro volumio[5640]: info: ----- MyVolumio plugins startup ---- Sep 01 03:59:11 spla-repro volumio[5640]: info: ------------------------------------------- Sep 01 03:59:11 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 03:59:11 spla-repro volumio[5640]: error: MPD error: The expression evaluated to a falsy value: Sep 01 03:59:11 spla-repro volumio[5640]: assert.ok(self.idling) Sep 01 03:59:11 spla-repro volumio[5640]: error: The expression evaluated to a falsy value: Sep 01 03:59:11 spla-repro volumio[5640]: assert.ok(self.idling) Sep 01 03:59:11 spla-repro volumio[5640]: info: MPD running with PID5823 Sep 01 03:59:11 spla-repro volumio[5640]: ,establishing connection Sep 01 03:59:11 spla-repro volumio[5640]: error: updateQueue error: null Sep 01 03:59:11 spla-repro volumio[5640]: error: updateQueue error: null Sep 01 03:59:12 spla-repro sudo[5927]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:12 spla-repro sudo[5925]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:12 spla-repro sudo[5927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 03:59:12 spla-repro sudo[5927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:12 spla-repro sudo[5925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 03:59:12 spla-repro sudo[5925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:12 spla-repro sudo[5927]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:12 spla-repro sudo[5925]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:12 spla-repro sudo[5931]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:12 spla-repro sudo[5931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 03:59:12 spla-repro sudo[5931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:12 spla-repro sudo[5931]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:12 spla-repro volumio[5640]: info: Upmpdcli Daemon Started Sep 01 03:59:12 spla-repro volumio[5640]: info: go-librespot daemon successfully initialized Sep 01 03:59:13 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 03:59:13 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:13 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:13 spla-repro go-librespot[5933]: go-librespot daemon starting... Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="app state loaded" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+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]" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+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]" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=info msg="zeroconf server listening on port 45691" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="obtained new client token: AAFQl+769aaBSBSI6tphGfZuOVvBkghEd72fo9Dnb5FYudPX9nZ+mK/rk/yV9XDF7w6jnLZ/k7EsKfMROW/bsNdnuyZSb4Yj2ZxutK8EsnJMUQ8bbip7vS0PzUG5lwgOhKQ4QBvAiRkC+nzKMelrwKYsUs8MHxJg8WSjBApmM/mBofzgDPxXvOMCjc1lhTuUrykS0FMkU9muQymVCwUUnelNSf/U0Nd9Xo5POcyV1Yuv9RzbEKXLW3IXpQ==" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=debug msg="completed challenge" Sep 01 03:59:13 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:13 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:13 spla-repro go-librespot[5934]: time="2026-09-01T03:59:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:13 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:13 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:15 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:15 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:16 spla-repro volumio[5640]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 03:59:16 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 03:59:16 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:17 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:17 spla-repro go-librespot[5944]: go-librespot daemon starting... Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="app state loaded" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+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]" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+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]" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=info msg="zeroconf server listening on port 36883" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="obtained new client token: AAFHCCWoPzSMq5im8C9+gRO3wPpCIiRkh5Wcu7/jchV3RDHEAHkyejXIGP2IObh9d+TK6LjgDQ4wXYUp38FJjU1Ia9oaxuWOt4z1ndAcgKQpiGstSlUiSfXw/OucTVAlgwEjCnmt8cQEqzhmwFQj3piaEZEqMg1WZ2oI5WGGE/crnTKwHYgZx4bF/0D1qcToT1ShSY8j96IwL+HxTEzJUptTNQ7YnDS6ddxgrh1sF7NVf22dztOAdHqP7A==" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=debug msg="completed challenge" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:17 spla-repro go-librespot[5945]: time="2026-09-01T03:59:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:17 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:17 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:18 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:18 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 03:59:20 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 03:59:20 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 03:59:20 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:20 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:20 spla-repro go-librespot[5955]: go-librespot daemon starting... Sep 01 03:59:20 spla-repro go-librespot[5956]: time="2026-09-01T03:59:20+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:20 spla-repro go-librespot[5956]: time="2026-09-01T03:59:20+02:00" level=debug msg="app state loaded" Sep 01 03:59:20 spla-repro go-librespot[5956]: time="2026-09-01T03:59:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=info msg="zeroconf server listening on port 34833" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="obtained new client token: AAGhJ5VnmAGh18cjfN0EjJpQ3yKjGSAKcz1k6ncNyXPvyd1wahI6FdAtHoidrT/YgzJSTgFBs1SkDq+WHqxvmDSCvpJQx0rMR1NeMSPewUSv3BYYmAJiYoXQEU3sv/5TDlOPBVK33WQD1nWLSEarH/NdqxyGpPwkCJY1uoQ77Cx5G1fO1O7fmjWAK9zQe0QQp2LhIh2myV8oATBjRFz64FGFbKioSRSykLt5oVHy1VUdGxPuj6QKqtU=" Sep 01 03:59:21 spla-repro volumio[5640]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:21 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 03:59:21 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:21 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:21 spla-repro volumio[5640]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 03:59:21 spla-repro volumio[5640]: info: MyVolumio login type: Token Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=debug msg="completed challenge" Sep 01 03:59:21 spla-repro volumio[5640]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 03:59:21 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:21 spla-repro go-librespot[5956]: time="2026-09-01T03:59:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:21 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:21 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:22 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 03:59:22 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 03:59:22 spla-repro volumio[5640]: info: Streaming services startup Sep 01 03:59:22 spla-repro volumio[5640]: info: Starting Streaming Daemon Sep 01 03:59:22 spla-repro sudo[5981]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:22 spla-repro sudo[5981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 03:59:22 spla-repro volumio[5640]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 03:59:22 spla-repro sudo[5981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:22 spla-repro sudo[5981]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:22 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:22 spla-repro volumio[5640]: error: Cannot start Volumio Streaming Daemon Sep 01 03:59:22 spla-repro volumio[5640]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 03:59:22 spla-repro volumio[5640]: sudo: unable to resolve host spla-repro: System error Sep 01 03:59:22 spla-repro volumio[5640]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 03:59:22 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:22 spla-repro volumio[5640]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 03:59:23 spla-repro volumio[5640]: info: MyVolumio token set successfully Sep 01 03:59:23 spla-repro volumio[5640]: info: MYVOLUMIO: Adding device Sep 01 03:59:23 spla-repro volumio[5640]: info: MYVOLUMIO: Evaluating Server Sep 01 03:59:23 spla-repro volumio[5640]: info: MyVolumio status changed Sep 01 03:59:23 spla-repro volumio[5640]: info: Streaming services startup Sep 01 03:59:23 spla-repro volumio[5640]: info: Starting Streaming Daemon Sep 01 03:59:23 spla-repro volumio[5640]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 03:59:23 spla-repro volumio[5640]: info: Removing audio output: Sep 01 03:59:23 spla-repro volumio[5640]: info: Stoppping Tunnel 1 Sep 01 03:59:23 spla-repro sudo[6009]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:23 spla-repro sudo[6009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 03:59:23 spla-repro sudo[6009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:23 spla-repro sudo[6009]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:23 spla-repro sudo[6012]: volumio : unable to resolve host spla-repro: System error Sep 01 03:59:23 spla-repro sudo[6012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 03:59:23 spla-repro sudo[6012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 03:59:23 spla-repro volumio[5640]: error: Cannot start Volumio Streaming Daemon Sep 01 03:59:23 spla-repro volumio[5640]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 03:59:23 spla-repro volumio[5640]: sudo: unable to resolve host spla-repro: System error Sep 01 03:59:23 spla-repro volumio[5640]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 03:59:23 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:23 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:23 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:23 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:23 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. Sep 01 03:59:23 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. Sep 01 03:59:23 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. Sep 01 03:59:23 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. Sep 01 03:59:23 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. Sep 01 03:59:23 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. Sep 01 03:59:23 spla-repro sudo[6012]: pam_unix(sudo:session): session closed for user root Sep 01 03:59:23 spla-repro volumio[5640]: info: Remote SSH Stopped Sep 01 03:59:24 spla-repro volumio[5640]: info: Setting Geolocation for MyVolumio to eu6 Sep 01 03:59:24 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:24 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:24 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:24 spla-repro volumio[5640]: info: Successfully Added MyVolumio device Sep 01 03:59:24 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 03:59:24 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:24 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:24 spla-repro go-librespot[6014]: go-librespot daemon starting... Sep 01 03:59:24 spla-repro go-librespot[6015]: time="2026-09-01T03:59:24+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:24 spla-repro go-librespot[6015]: time="2026-09-01T03:59:24+02:00" level=debug msg="app state loaded" Sep 01 03:59:24 spla-repro go-librespot[6015]: time="2026-09-01T03:59:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+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]" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+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]" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=info msg="zeroconf server listening on port 42441" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:25 spla-repro volumio[5640]: info: Updating MyVolumio device info Sep 01 03:59:25 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:25 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:25 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=debug msg="obtained new client token: AAEfzGgw06sl9NCiMgHFXQAv9ev//4gDQgHW/zXYHCeBvhtxhpitNApxr7bvO4E/PCqx2rOdkORf/tXg6y82HYdomeIvBGwfX+rPOxGoLdd7ovT0SJcABGaLtvaMWAgSPhCRuX1gcLV0hGI+zOqovOtQiHpn6MZAaLEkMQBpq6bXjGQYCqP9ro9+nXBfJItNWKhGwRiAOx9zuei/Qnh0vcispg1PQUuXc3rX5NJNLK5H2c3xgXW2B00=" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=debug msg="completed challenge" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:25 spla-repro go-librespot[6015]: time="2026-09-01T03:59:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:25 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:25 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:25 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:25 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:25 spla-repro volumio[5640]: info: Successfully Updated MyVolumio device Sep 01 03:59:28 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:28 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:28 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 03:59:28 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:28 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:28 spla-repro go-librespot[6024]: go-librespot daemon starting... Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=debug msg="app state loaded" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+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]" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+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]" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=info msg="zeroconf server listening on port 36573" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=debug msg="obtained new client token: AAEIOlSohIDQN4kXVmxSk3AQhsBzwQl3ioOZD2M5g3qBCGU3yxBCGL5nO/eE/RtyI2rM3W+HcSzt1IgBEDrv69PR1csI6lykkztHESe6hLIqY86eXgG4bGr3B+ddfQcyLZF/4b5gmwRhdWE5aqyo76jSl5MNilxZot2T01+WZERNESN/MItdZsRloOoi4XkXNfCA4iZMZ4YTKet8YFG9jDaBv0Z54ssn5Y7OenH2tprKwTRXIpagjdXU/A==" Sep 01 03:59:28 spla-repro go-librespot[6025]: time="2026-09-01T03:59:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:29 spla-repro go-librespot[6025]: time="2026-09-01T03:59:29+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:29 spla-repro go-librespot[6025]: time="2026-09-01T03:59:29+02:00" level=debug msg="completed challenge" Sep 01 03:59:29 spla-repro go-librespot[6025]: time="2026-09-01T03:59:29+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:29 spla-repro go-librespot[6025]: time="2026-09-01T03:59:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:29 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:29 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:31 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:31 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:32 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 03:59:32 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:32 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:32 spla-repro go-librespot[6049]: go-librespot daemon starting... Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="app state loaded" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+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]" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+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]" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=info msg="zeroconf server listening on port 38443" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="obtained new client token: AAGDZThaeW1QnZjcNzRQ8e+A3pVQ8Oo8tVgz/5F1ejICeiwNMKDiOfl64jgDeIwRw6FoPTAOYdUoC9t3SQaZAz9IXB+52oZk9c34Tbvkzz85vsNz1XPRZKTlkJgOsKnvxXOjgth/RBYpWSxMCZqSIYyeVwzgkrIMg/SkAYAwp5z+Ulfoj25M2z4veXGy7y6Foe2PeGnhLgS36VZQqF6MvuyWu/iYbSzGcmvrzqNhxGE7a1USeESdWXjS4g==" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=debug msg="completed challenge" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:32 spla-repro go-librespot[6050]: time="2026-09-01T03:59:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:32 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:32 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:33 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:33 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:34 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:34 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:35 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 03:59:35 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:36 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:36 spla-repro go-librespot[6059]: go-librespot daemon starting... Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=debug msg="app state loaded" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+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]" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+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]" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+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]" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=info msg="zeroconf server listening on port 38701" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:36 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 03:59:36 spla-repro volumio[5640]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 01 03:59:36 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:36 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=debug msg="obtained new client token: AAGXVpthYYE+vo6WuGQdMgXn+13JafuZKQ+SxQMixO80Tg6AtT1M+GOSdNili74zlmwv3Is3SWxfDtyCKVmGWI4kEorK01QuHVzQs2MJrWBrR4OOmkN4z3dSwqzFk3JSR2MgSKVtMYJBhWZiBcQY60GaRzlYD4OlNBk4Zn0ozXC7o23zi2cI7/D65BMb17RBBCVnKafkoDWzYfLvbrDy4q3HKs4owtsH0wuzK1KIxA27JMPH9Neg9q7brQ==" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=debug msg="completed challenge" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:36 spla-repro go-librespot[6060]: time="2026-09-01T03:59:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:36 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:36 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:37 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:37 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:37 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 03:59:37 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:37 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 03:59:38 spla-repro volumio-remote-updater[725]: Test mode disabled Sep 01 03:59:38 spla-repro volumio-remote-updater[725]: Alpha mode disabled Sep 01 03:59:38 spla-repro volumio-remote-updater[725]: Alpha legacy test mode disabled Sep 01 03:59:38 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 03:59:38 spla-repro volumio[5640]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 03:59:38 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 03:59:39 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 03:59:39 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:39 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:39 spla-repro go-librespot[6073]: go-librespot daemon starting... Sep 01 03:59:39 spla-repro go-librespot[6074]: time="2026-09-01T03:59:39+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:39 spla-repro go-librespot[6074]: time="2026-09-01T03:59:39+02:00" level=debug msg="app state loaded" Sep 01 03:59:39 spla-repro go-librespot[6074]: time="2026-09-01T03:59:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+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]" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+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]" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+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]" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=info msg="zeroconf server listening on port 33077" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=debug msg="obtained new client token: AAE5F6kRRteDWwNSUToRa1IpQhFBYNWeXXPlxor8yquxPt6lXG/htMkvfkaUgvfLwZt+Vzoa5yqfqQRYKcGKJhvJ3k5in8ZwZff1HB9x5r16xg7ezsCoDOeyFd2Bt50VTUXzEl5ziTOUI2Llh7T9A/5/2xdz0st6/0UxYJmkodzQ8Gdwza4hvozqQW3FBZ0D5Eez9fOoyDGOKu5dY4kywd90od756QsYWzWhozqzEiGFkvymhZIdzuI=" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=debug msg="completed challenge" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:40 spla-repro go-librespot[6074]: time="2026-09-01T03:59:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:40 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:40 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:40 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:40 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 03:59:41 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 03:59:42 spla-repro volumio[5640]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 01 03:59:42 spla-repro volumio[5640]: info: Completed starting MyVolumio Plugin Sep 01 03:59:42 spla-repro volumio[5640]: [Metrics] CommandRouter: 42s 605.77ms Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 03:59:42 spla-repro volumio[5640]: info: VolumeController:: Setting startup Volume 45 Sep 01 03:59:42 spla-repro volumio[5640]: info: VolumeController::SetAlsaVolume45 Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::Close All Modals sent Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::Close All Modals sent Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreStateMachine::pushState Sep 01 03:59:42 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 03:59:42 spla-repro volumio[5640]: info: CoreCommandRouter::volumioPushState Sep 01 03:59:43 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 01 03:59:43 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 03:59:43 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 01 03:59:43 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:43 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:43 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 03:59:43 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:43 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:43 spla-repro go-librespot[6098]: go-librespot daemon starting... Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=debug msg="app state loaded" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:43 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:43 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:43 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:43 spla-repro volumio[5640]: info: Listing playlists Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+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]" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+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]" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+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]" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=info msg="zeroconf server listening on port 43167" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:43 spla-repro go-librespot[6099]: time="2026-09-01T03:59:43+02:00" level=debug msg="obtained new client token: AAEmT5bq2ZwFk2zQU4ZGoZlnsUZKHyr0fmKaQE9DkPY5bbfB9gj+8UAn97/GwlWslr+yw62eefMB6tyIAIgoLpMHJ324LO6xRWhd9BHhAPAGwA9FmQ+1TMTusjXK9w51OUFeRDiYggAn5dknBj0wvLcWBT8QposydNwUH1ic0/XnFtjO8d1oPI2k0sEPiW7fF2hqU9FEMBtWvCnYGiogSX/dhK55cJZeWOO5I3vjmpAbkqHfXkug9KodjQ==" Sep 01 03:59:44 spla-repro go-librespot[6099]: time="2026-09-01T03:59:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:44 spla-repro go-librespot[6099]: time="2026-09-01T03:59:44+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:44 spla-repro go-librespot[6099]: time="2026-09-01T03:59:44+02:00" level=debug msg="completed challenge" Sep 01 03:59:44 spla-repro go-librespot[6099]: time="2026-09-01T03:59:44+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:44 spla-repro go-librespot[6099]: time="2026-09-01T03:59:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:44 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:44 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:46 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:46 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:47 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 01 03:59:47 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:47 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:47 spla-repro go-librespot[6108]: go-librespot daemon starting... Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=debug msg="app state loaded" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+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]" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+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]" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+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]" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=info msg="zeroconf server listening on port 42277" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=debug msg="obtained new client token: AAH0UlYGyxxrjtwo9ybKqLs5FLNuUJ9Cx7kCdWrimb3SfVtUTKEXxEfGrhbdvB900hxkKkATzoRuTMIPSVxKV0ycKBNRqI6Qga3G1aNetlPNt3wgrV6ZEiHlaUPj1M+z2B9tLNXMotQQmLyQvdzL3NCOUNy0zRdjuD/hv+fdUiVKJoD55QQdMNCAuDmp5BZCHyxX9h3mz2Up2nFVcAnWHZ1VaFJ1pJJ//P78IK+0+uWIAVYD/dTVBd8cxg==" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=debug msg="completed challenge" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:47 spla-repro go-librespot[6109]: time="2026-09-01T03:59:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:47 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:47 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:49 spla-repro volumio[5640]: info: BOOT COMPLETED Sep 01 03:59:49 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:49 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:50 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 01 03:59:50 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:51 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:51 spla-repro go-librespot[6118]: go-librespot daemon starting... Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="app state loaded" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+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]" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+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]" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=info msg="zeroconf server listening on port 34973" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="obtained new client token: AAGCe98QBLAwdgIHL8dxW4W8/6Rl2vcG4RgGbU2OhxbohdMw9EWiYSQxw1NTIIT014g9LAJ98bZpM75v7HzhOqHgiLz+UbdShy5RJaKIe/6kbYwCwXU7xoFt4K46zi2JRwItI0yPkG9evcYJ6BknnycyI54lQoDjEKwRIg56kub/tN00jT7xsCJ4cMvoVGwxb0dnN9QEn6rdvPDfD1bdlPwtQFey6LtzCi/1A/G/d1DKCDbTidXiu0VaaQ==" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=debug msg="completed challenge" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:51 spla-repro go-librespot[6119]: time="2026-09-01T03:59:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:51 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:51 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:52 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:52 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:53 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 03:59:53 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 03:59:54 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 01 03:59:54 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:54 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:54 spla-repro go-librespot[6144]: go-librespot daemon starting... Sep 01 03:59:54 spla-repro go-librespot[6145]: time="2026-09-01T03:59:54+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:54 spla-repro go-librespot[6145]: time="2026-09-01T03:59:54+02:00" level=debug msg="app state loaded" Sep 01 03:59:54 spla-repro go-librespot[6145]: time="2026-09-01T03:59:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+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]" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+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]" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=info msg="zeroconf server listening on port 46021" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=debug msg="obtained new client token: AAFPO0mE8ry/fMCUYJs2bwuTrLjH2B2h50uMAQ5w3WHHyZrHHnBQZk39Ax6PlYwjtu2YgPAOeIfqHXQNlHw1UfFp1KN177sL4jjCHAqbZ2t1zjpxDcLzX2I51tNUtHETnDCezxzild/jcMtS7Gik7elYcZ/0fyBhltXG/hZ+iVBS0GrhodJsm0YMHtkegkf+4/pIGVx77TOyRavU+3Ut7vB5qxvaJ+z0Evv+bzyUEmGEevm8o4vADS8=" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=debug msg="completed challenge" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:55 spla-repro go-librespot[6145]: time="2026-09-01T03:59:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:55 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:55 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 03:59:55 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:55 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:58 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 03:59:58 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:58 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 03:59:58 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 03:59:58 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 03:59:58 spla-repro go-librespot[6154]: go-librespot daemon starting... Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=debug msg="app state loaded" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=info msg="zeroconf server listening on port 33871" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 03:59:58 spla-repro go-librespot[6155]: time="2026-09-01T03:59:58+02:00" level=debug msg="obtained new client token: AAGizaZTsyt5KzTDSwKomVH1WZxvUUtZHW8k4vse7GrqJwKhz15Ko54+IBWH3y3Zpqd75vsuTCr4h1SojeTJQZDinaLkk3b0ytQ0w/gvo4ULlUWsY+L486iQgjnevPKWf8TyZD/qUUzfQSoEOrr7KCGHJ6id3a4H6Wwvsbc+7+9fKH0ygQBerrRpngTlfdsdiQpNOdmSAxcsgRsRiDknKzlRHY8NmMyx/rvESM1h7J6hNtQRjcz5z0BG6g==" Sep 01 03:59:59 spla-repro go-librespot[6155]: time="2026-09-01T03:59:59+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 03:59:59 spla-repro go-librespot[6155]: time="2026-09-01T03:59:59+02:00" level=debug msg="completed keyexchange" Sep 01 03:59:59 spla-repro go-librespot[6155]: time="2026-09-01T03:59:59+02:00" level=debug msg="completed challenge" Sep 01 03:59:59 spla-repro go-librespot[6155]: time="2026-09-01T03:59:59+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 03:59:59 spla-repro go-librespot[6155]: time="2026-09-01T03:59:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 03:59:59 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 03:59:59 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:01 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:01 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:02 spla-repro systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Sep 01 04:00:02 spla-repro systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Sep 01 04:00:02 spla-repro systemd[1]: welcome.service: Deactivated successfully. Sep 01 04:00:02 spla-repro systemd[1]: Stopped welcome.service - Show a welcome message on console. Sep 01 04:00:02 spla-repro systemd[1]: Stopping welcome.service - Show a welcome message on console... Sep 01 04:00:02 spla-repro systemd[1]: Starting welcome.service - Show a welcome message on console... Sep 01 04:00:02 spla-repro welcome[6196]: Resolved ip:[1] 192.168.200.203 Sep 01 04:00:02 spla-repro systemd[1]: Finished welcome.service - Show a welcome message on console. Sep 01 04:00:02 spla-repro systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Sep 01 04:00:02 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 01 04:00:02 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:02 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:02 spla-repro go-librespot[6201]: go-librespot daemon starting... Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="app state loaded" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:02 spla-repro volumio[5640]: info: Received Get System Info Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:00:02 spla-repro volumio[5640]: info: Discovery: Getting this device information Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 04:00:02 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:00:02 spla-repro volumio[5640]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+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]" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+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]" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=info msg="zeroconf server listening on port 44251" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="obtained new client token: AAEZrO5IfrXQLikBEH/sSDDgJcoUl7twhlKRf6LAvYo8iegeABcHJ4MNaxNoAq8yRTODKIUCMfVFZne3YD3DuROsvtrk1hwiGXf1GuXiSfNbFSaR9dUbg5B7H8gdUrmnjPYkTtsWnj/ySu1iKcIMcfuNSMTW94pPpSVVFZfOuDH8+ud/oMXCgBVhu+icZNeHmaWG26CSVVPSprRaGyssLnghBdC25x0lBu0o5R/qdlUl1dr1b6v1hpog2Q==" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=debug msg="completed challenge" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:02 spla-repro go-librespot[6202]: time="2026-09-01T04:00:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:02 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:02 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:03 spla-repro volumio5-onboarding[4505]: time=2026-09-01T04:00:03.360+02:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:00:03 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 04:00:03 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 04:00:03 spla-repro volumio[5640]: info: Listing playlists Sep 01 04:00:03 spla-repro volumio[5640]: info: Listing playlists Sep 01 04:00:04 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:04 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:05 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Sep 01 04:00:05 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:06 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:06 spla-repro go-librespot[6211]: go-librespot daemon starting... Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="app state loaded" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+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]" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+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]" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=info msg="zeroconf server listening on port 42165" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="obtained new client token: AAFgzgZ+pVVqYQearyoWTa2u4NkiFV6cBjZzfECwMuIdbb1CsmPEIorV1B4HGgwoED3m0RZeYMhOaqeqzurkeUPkB5FE8o7yjsW8nBSc7djKQKZz0f2StB3z6Eb7jSD6T82AXzGVCehOvKx51fV8P/Ftm6bgECk5mtYaSMUTE1U6x+x5WhDLzTD4pBUv7syW68jTNxGA0D+nOJgxYyofdo5jK3J5U6dJh7MoaSse1Cp9SSywQ3OIO8ZkcA==" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=debug msg="completed challenge" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:06 spla-repro go-librespot[6212]: time="2026-09-01T04:00:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:06 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:06 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:07 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:07 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:09 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Sep 01 04:00:09 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:09 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:09 spla-repro go-librespot[6222]: go-librespot daemon starting... Sep 01 04:00:09 spla-repro go-librespot[6223]: time="2026-09-01T04:00:09+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:09 spla-repro go-librespot[6223]: time="2026-09-01T04:00:09+02:00" level=debug msg="app state loaded" Sep 01 04:00:09 spla-repro go-librespot[6223]: time="2026-09-01T04:00:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00: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]" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00: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]" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00: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]" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=info msg="zeroconf server listening on port 44591" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=debug msg="obtained new client token: AAGJ2GMMgdwMD2GDwuAV3wYUsZ0jlns7qgNOnDjL+phi/QaIr7DPfTjZ5836hFTLVXMnuEzNAdMqkRUr36InUkezUZApyC2DyIzXCHeqVAgLGFCsqMePZhRlksdTdcQQilJfTssW/7Omhx+36Z4h2veXYJimX0hASqTIj4Ve4gREF6rVc1MIqtILLOodEFSnrgXoVjK2NPBtvN0lTdHx55DnDMhoInfsjLDP3BDw9TSFHfwqMK5pFiM=" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=debug msg="completed challenge" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:10 spla-repro go-librespot[6223]: time="2026-09-01T04:00:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:10 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:10 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:10 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:10 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:13 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Sep 01 04:00:13 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:13 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:13 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:13 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:13 spla-repro go-librespot[6247]: go-librespot daemon starting... Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=debug msg="app state loaded" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:13 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 04:00:13 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=info msg="zeroconf server listening on port 36763" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:13 spla-repro go-librespot[6248]: time="2026-09-01T04:00:13+02:00" level=debug msg="obtained new client token: AAEoRCByxyxHURuCU0ydrbRcRm7AVNsVakAehV4HQzox6qhuX7iherX/xoiTmQz5DYAqBuJLER8zCAnMJLm2XKLjrDeXexRn3e7R7RdcwkH1rrWU1wYGRiFLyF2f6MsxryQE1jIS//PWwUJs1lpR492D58vZWQHtPBQJLoxKsmCE7Z1DE7uYtNdCHYyTxDD4VnVp+tAQ7pb8BKWn7BG6Y+RfGrdY1OWbh0csNp7AhdAx/6bNOAwhuu0RbQ==" Sep 01 04:00:14 spla-repro go-librespot[6248]: time="2026-09-01T04:00:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:14 spla-repro go-librespot[6248]: time="2026-09-01T04:00:14+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:14 spla-repro go-librespot[6248]: time="2026-09-01T04:00:14+02:00" level=debug msg="completed challenge" Sep 01 04:00:14 spla-repro go-librespot[6248]: time="2026-09-01T04:00:14+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:14 spla-repro go-librespot[6248]: time="2026-09-01T04:00:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:14 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:14 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:16 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:16 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:17 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Sep 01 04:00:17 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:17 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:17 spla-repro go-librespot[6259]: go-librespot daemon starting... Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="app state loaded" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=info msg="zeroconf server listening on port 37065" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="obtained new client token: AAENVVwnUFDiA91NtyHr7Da+R6s9vxPItlZoIChR9zRkz1MujkxhGbTE8QuXJVp+VuvuLJLnJlcvhoMNaQ4djJzTa1osObOYboKXUbmrLfutAOc7ZlD0g2Fx6s8dC6c+tDreSFUB2Sn9sSPZdcQ7zmyx0wi/ACYf00QaDsBQDJUDAkx9UyLLnIwBbZhDdWnPEaRafwZTsoiyCIf8QamdR8pe+98KHP5i7+5Wr5/ro8VHCeR1Ssf9a6sbTw==" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=debug msg="completed challenge" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:17 spla-repro go-librespot[6260]: time="2026-09-01T04:00:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:17 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:17 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:19 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:19 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:20 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Sep 01 04:00:20 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:21 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:21 spla-repro go-librespot[6269]: go-librespot daemon starting... Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="app state loaded" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+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]" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+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]" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=info msg="zeroconf server listening on port 35549" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="obtained new client token: AAGKgb/yRPK0fzTIjtZC5BDYgzvB0fCn2469kR/CTZJ/gPaUrkSlONOUXIQ+5OZmSrqYV8OiwwuVLrrrEUEQYQbiPvfdytls7bt+vJFLNSSiReuHZAPjoeDEtENR6f9W6Nt3nfEiWwgOgA8hHUSASUFIgBQM5xMvphHsrlQQJZdo1GyqVo7cn8y76gjHD5PIPJ/pkffyAlnTL8xNTcDw7MiJ50M1SpVbmb/rfGh8C1qa0E/xgLg8sD2NwQ==" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=debug msg="completed challenge" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:21 spla-repro go-librespot[6270]: time="2026-09-01T04:00:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:21 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:21 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:22 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:22 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:23 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 04:00:23 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 04:00:23 spla-repro volumio[5640]: info: Listing playlists Sep 01 04:00:23 spla-repro volumio[5640]: info: Listing playlists Sep 01 04:00:24 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Sep 01 04:00:24 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:24 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:24 spla-repro go-librespot[6293]: go-librespot daemon starting... Sep 01 04:00:24 spla-repro go-librespot[6294]: time="2026-09-01T04:00:24+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:24 spla-repro go-librespot[6294]: time="2026-09-01T04:00:24+02:00" level=debug msg="app state loaded" Sep 01 04:00:24 spla-repro go-librespot[6294]: time="2026-09-01T04:00:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+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]" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+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]" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=info msg="zeroconf server listening on port 45981" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=debug msg="obtained new client token: AAF5n93zWwHk6QTg5rEEX254j7NE1/J3YKZqyarkYlcMijj7b7RnTH88CuuR8BBoz+wiILUhphwi7UwlZLUf1MGesnfuQYV8kB1QC8+8o2IVGeiC5/w9KqljUg4BRtCGYaOi51XyRN7M4TkpXpJVO7mzjHHDDg1lL/h/2FzOrzTXhCShAFh/TOcXl5J5SQ5Y+VujSqW88Wmij6DNjGuqQrWY057hy+yZpR78qT3rt1eQ2zh80AQd1pU=" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=debug msg="completed challenge" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:25 spla-repro go-librespot[6294]: time="2026-09-01T04:00:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:25 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:25 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:25 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:25 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:28 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Sep 01 04:00:28 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:28 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:28 spla-repro go-librespot[6303]: go-librespot daemon starting... Sep 01 04:00:28 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:28 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="app state loaded" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=info msg="zeroconf server listening on port 42971" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="obtained new client token: AAGTLsLqnB0WC6ZZM59onY8P4wNePXMYhhAN3k2r278K6zAnIdox1tCsZFmXzubb4iHy/gxVx96FeqXLmBwpz0PJiuL64m6Ofe/GPyDctvx5LrLXZJPjtF09/UbS56w5j+m7P15KBySLKEBTdu6LjEnd18ojGbzDIwipMZTkqboSoE4fFoUExFMsqyQsd3aHPOyVBUebxoXF3mmJ+rOtMnEV+BI7rHm/OqvB7+vkthrIVCgawKy63I2r2w==" Sep 01 04:00:28 spla-repro go-librespot[6304]: time="2026-09-01T04:00:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:29 spla-repro go-librespot[6304]: time="2026-09-01T04:00:29+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:29 spla-repro go-librespot[6304]: time="2026-09-01T04:00:29+02:00" level=debug msg="completed challenge" Sep 01 04:00:29 spla-repro go-librespot[6304]: time="2026-09-01T04:00:29+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:29 spla-repro go-librespot[6304]: time="2026-09-01T04:00:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:29 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:29 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:31 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:31 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:32 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Sep 01 04:00:32 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:32 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:32 spla-repro go-librespot[6328]: go-librespot daemon starting... Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="app state loaded" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=info msg="zeroconf server listening on port 39801" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="obtained new client token: AAEDc4C8ZDI7Vwx8ErLYgECYYFgTpe0kAeVjGXQ2Dz+IWbUVzoLcv+/RE8WGEX9oLANIshC7d4i8IaVCXLx8tHqxaqYZiux58JyJ8kUqxPbArAJdE604dwzyUrwpe4+EOKjMSmkc6eWKi1P7oVWJzJ02xP4lecsW6VwI3Y9RP/S0VpHWqRr599ISX/OgOq5U+oi37QUv8OkDTd5L03OKwTdmUfWPQBsula+eKl+80ZcKxaIYX1NqNt8vEw==" Sep 01 04:00:32 spla-repro go-librespot[6329]: time="2026-09-01T04:00:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:33 spla-repro go-librespot[6329]: time="2026-09-01T04:00:33+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:33 spla-repro go-librespot[6329]: time="2026-09-01T04:00:33+02:00" level=debug msg="completed challenge" Sep 01 04:00:33 spla-repro go-librespot[6329]: time="2026-09-01T04:00:33+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:33 spla-repro go-librespot[6329]: time="2026-09-01T04:00:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:33 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:33 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:33 spla-repro volumio[5640]: info: CoreCommandRouter::volumioGetState Sep 01 04:00:33 spla-repro volumio[5640]: info: CorePlayQueue::getTrack 0 Sep 01 04:00:34 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:34 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:36 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Sep 01 04:00:36 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:36 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:36 spla-repro go-librespot[6338]: go-librespot daemon starting... Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=debug msg="app state loaded" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+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]" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+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]" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+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]" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=info msg="zeroconf server listening on port 46307" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=debug msg="obtained new client token: AAHqgKrCbqjloMmLGDQcxqGi0u6suB5CCn6qaVrn11p/NmTpwj2msZT8QIy49IsJu3bHw/i1CHvbcRejynNocC2Uwk0AvoB+XCraJI9cH9aWp8DgVBfMsmmg7nGsrUT8dOT5Gl7k7vlpQlar3Rlvw3TTC1VRlMb/lMlKoMO671uEs68YrANxEVxZJUVAeJseJfe9m/dCEz3BFO+VqqGdS4qQCSajkBME4h5X7B89Y4AtvJyJtBGVv+6qwg==" Sep 01 04:00:36 spla-repro go-librespot[6339]: time="2026-09-01T04:00:36+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:37 spla-repro go-librespot[6339]: time="2026-09-01T04:00:37+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:37 spla-repro go-librespot[6339]: time="2026-09-01T04:00:37+02:00" level=debug msg="completed challenge" Sep 01 04:00:37 spla-repro go-librespot[6339]: time="2026-09-01T04:00:37+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:37 spla-repro go-librespot[6339]: time="2026-09-01T04:00:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:37 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:37 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:37 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:37 spla-repro volumio[5640]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:40 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Sep 01 04:00:40 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:40 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:40 spla-repro go-librespot[6348]: go-librespot daemon starting... Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="app state loaded" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:40 spla-repro volumio[5640]: info: Initializing connection to go-librespot Websocket Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="new websocket client" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+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]" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+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]" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+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]" Sep 01 04:00:40 spla-repro volumio[5640]: info: Connection to go-librespot Websocket established Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=info msg="zeroconf server listening on port 33129" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="obtained new client token: AAE9aHDQZ/LAr5HI36lyE2nTKJ2Q9zOh02kN8kphcdHPebZCWkiPaC4ZLKYRzbBvikn54ipWHGJQZHFvOiO7jxdmszHK7aeFimW5SzpnkKu+E6xlLHllNbERxHIVJvTjewti65UNwK4gT7YUAG3TmSOf+3a8oFdgzBHHvyrX+Dv18an277GPctWr/+v9/uFTmb4m5h0tdGwiTdxvkwjsNtlyDO/qN9SM0pPuDRecDyW5g5gF6oL1FeCksA==" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=debug msg="completed challenge" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=info msg="authenticated AP" username="4b*********************lb" Sep 01 04:00:40 spla-repro go-librespot[6349]: time="2026-09-01T04:00:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:00:40 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:00:40 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:00:40 spla-repro volumio[5640]: info: Connection to go-librespot Websocket closed Sep 01 04:00:43 spla-repro volumio[5640]: info: Getting Spotify volume Sep 01 04:00:43 spla-repro volumio[5640]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 04:00:43 spla-repro volumio[5640]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:00:43 spla-repro volumio[5640]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 04:00:43 spla-repro volumio[5640]: errno: -111, Sep 01 04:00:43 spla-repro volumio[5640]: code: 'ECONNREFUSED', Sep 01 04:00:43 spla-repro volumio[5640]: syscall: 'connect', Sep 01 04:00:43 spla-repro volumio[5640]: address: '127.0.0.1', Sep 01 04:00:43 spla-repro volumio[5640]: port: 9879, Sep 01 04:00:43 spla-repro volumio[5640]: response: undefined Sep 01 04:00:43 spla-repro volumio[5640]: } Sep 01 04:00:43 spla-repro volumio[5640]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 04:00:43 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Sep 01 04:00:43 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:44 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:00:44 spla-repro go-librespot[6384]: go-librespot daemon starting... Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=debug msg="app state loaded" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+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]" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+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]" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=info msg="zeroconf server listening on port 35899" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:00:44 spla-repro sudo[6396]: volumio : unable to resolve host spla-repro: System error Sep 01 04:00:44 spla-repro sudo[6396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 03:59' Sep 01 04:00:44 spla-repro sudo[6396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=debug msg="obtained new client token: AAHhhzYteOGSUKQ0ie/68u7RnbMwjp6stNdRo73e/0aNL6yZhH5nNUG1kgYUOxbwnJ/gWYOHRoWgbVTXuyI2LFICo/uLPXfMq0bQw3svtIr2T92PnZVo8yFOR45VwG64N2/M48RsFPRGNylbTXwUIT9Hce3zoG2wE2zYcZQmkLa1MyRlmjwneZ2NgxxD+U+TrH5SuRIleMXWwMi83sGGhaaEJUIbLnFBX1RQ2L1Ev+oHqLBLjL/NZBoVXw==" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=debug msg="completed keyexchange" Sep 01 04:00:44 spla-repro go-librespot[6385]: time="2026-09-01T04:00:44+02:00" level=debug msg="completed challenge" 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"