Aug 25 17:29:00 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:00 spla-repro volumio[11072]: info: ----- Volumio3 ---- Aug 25 17:29:00 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:00 spla-repro volumio[11072]: info: ----- System startup ---- Aug 25 17:29:00 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:00 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 25 17:29:00 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:01 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:01 spla-repro go-librespot[11096]: go-librespot daemon starting... Aug 25 17:29:01 spla-repro volumio[11072]: info: MYVOLUMIO Environment detected Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="app state loaded" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:01 spla-repro volumio[11072]: info: Plugin folders cleanup Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning into folder /volumio/app/plugins/ Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category audio_interface Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category miscellanea Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category music_service Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category plugins.json Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category system_controller Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category user_interface Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning into folder /data/plugins/ Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category audio_interface Aug 25 17:29:01 spla-repro volumio[11072]: info: Scanning category music_service Aug 25 17:29:01 spla-repro volumio[11072]: info: Plugin folders cleanup completed Aug 25 17:29:01 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:01 spla-repro volumio[11072]: info: ----- Core plugins startup ---- Aug 25 17:29:01 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:01 spla-repro volumio[11072]: info: Loading plugins from folder /volumio/app/plugins/ Aug 25 17:29:01 spla-repro volumio[11072]: info: Adding plugin upnp to MyMusic Plugins Aug 25 17:29:01 spla-repro volumio[11072]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 25 17:29:01 spla-repro volumio[11072]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 25 17:29:01 spla-repro volumio[11072]: info: Loading plugins from folder /data/plugins/ Aug 25 17:29:01 spla-repro volumio[11072]: info: Loading plugin "system"... Aug 25 17:29:01 spla-repro volumio[11072]: info: Loading plugin "appearance"... Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=info msg="zeroconf server listening on port 44627" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="obtained new client token: AAH3wXdGUj8/Kb9mqrXHVHkCVABwSrnnD0N0WGUixzNLr/3nl2vCcwccHC8XMOUgVvcoK2Z2WTMSp5gYHYOKN2IIbh5r3zp9Nu48WVl7wnJb2FzqzpgXlLPZNd4haZiHc1BTcuEPylgqvUagUyK7T9+pv9TSyd3CGsk2QO403X0zA1Jl/DA1rfnQiVJUBmlF9mXo2/DUS5XY+TLfHKzjP3SAdhjBTTt8MHxa8U9uBPUxz9Mdz3DK5Rhy4g==" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=debug msg="completed challenge" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:01 spla-repro go-librespot[11100]: time="2026-08-25T17:29:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:01 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:01 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "network"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Refreshing Cached IP Addresses Aug 25 17:29:02 spla-repro sudo[11113]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:02 spla-repro sudo[11115]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:02 spla-repro sudo[11115]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 17:29:02 spla-repro sudo[11113]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 17:29:02 spla-repro sudo[11113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:02 spla-repro sudo[11113]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:02 spla-repro sudo[11115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "services"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "volumio5onboarding"... Aug 25 17:29:02 spla-repro sudo[11122]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:02 spla-repro sudo[11115]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:02 spla-repro sudo[11122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 25 17:29:02 spla-repro sudo[11122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "alsa_controller"... Aug 25 17:29:02 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "wizard"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "networkfs"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Starting Udev Watcher for removable devices Aug 25 17:29:02 spla-repro volumio[11072]: info: Ignoring mount for partition: boot Aug 25 17:29:02 spla-repro volumio[11072]: info: Ignoring mount for partition: volumio Aug 25 17:29:02 spla-repro volumio[11072]: info: Ignoring mount for partition: volumio_data Aug 25 17:29:02 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "volumio_command_line_client"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "upnp"... Aug 25 17:29:02 spla-repro volumio[11072]: info: [1787671742570] Starting Upmpd Daemon Aug 25 17:29:02 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "my_music"... Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "mpd"... Aug 25 17:29:02 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:02] [connect] Successful connection Aug 25 17:29:02 spla-repro volumio[11072]: info: Loading plugin "upnp_browser"... Aug 25 17:29:03 spla-repro sudo[11122]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:04 spla-repro volumio[11072]: info: Starting UPNP Browser Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "alarm-clock"... Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "airplay_emulation"... Aug 25 17:29:04 spla-repro volumio[11072]: info: Starting Shairport Sync Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "last_100"... Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "webradio"... Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "i2s_dacs"... Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "volumiodiscovery"... Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** For more information see Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:04 spla-repro volumio[11072]: *** WARNING *** For more information see Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** For more information see Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:04 spla-repro node[11072]: *** WARNING *** For more information see Aug 25 17:29:04 spla-repro volumio[11072]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 25 17:29:04 spla-repro volumio[11072]: info: Discovery: Started advertising with name: Spálňa-repro Aug 25 17:29:04 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:04 spla-repro volumio[11072]: info: Loading plugin "spop"... Aug 25 17:29:04 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 25 17:29:04 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:05 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:05 spla-repro go-librespot[11148]: go-librespot daemon starting... Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="app state loaded" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=info msg="zeroconf server listening on port 36121" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="obtained new client token: AAHAWuRtSBosQMi43Fabx6eDmgOjyEs3ke3dBRG66bG87PtRTzG7WUCBrRiHysOp+xmJpVnXThslU7eonJsIx+zgAv1raOu5L3k95hBm3EaJLhwxO7dmQB+hJ7WkB8+Gy62f1JMcCk311uK2gqmSN0JlYenbPV7L24B3Mlt4u7+kRVD/sk0BXHhDNRBXCwet5mFG9gkhQnixBZHD/a0A4QSSwAHPyXByvZeUponYL8pVTtzqDSXD4/KQ8Q==" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=debug msg="completed challenge" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:05 spla-repro go-librespot[11149]: time="2026-08-25T17:29:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:05 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:05 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:05 spla-repro volumio[11072]: info: Loading plugin "outputs"... Aug 25 17:29:05 spla-repro volumio[11072]: info: Loading plugin "albumart"... Aug 25 17:29:05 spla-repro volumio[11072]: info: Plugin example_plugin is not enabled Aug 25 17:29:05 spla-repro volumio[11072]: info: Loading plugin "inputs"... Aug 25 17:29:06 spla-repro volumio[11072]: info: Loading plugin "updater_comm"... Aug 25 17:29:06 spla-repro volumio[11072]: info: Plugin mpdemulation is not enabled Aug 25 17:29:06 spla-repro volumio[11072]: info: Loading plugin "rest_api"... Aug 25 17:29:06 spla-repro volumio[11072]: info: Loading plugin "websocket"... Aug 25 17:29:06 spla-repro volumio[11072]: info: Starting Socket.io Server version 1.7.4 Aug 25 17:29:06 spla-repro volumio[11072]: info: Plugin fusiondsp is not enabled Aug 25 17:29:06 spla-repro volumio[11072]: info: Loading i18n strings for locale sk Aug 25 17:29:06 spla-repro volumio[11072]: Updating browse sources language Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::initPlayerControls Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: Express server listening on port 3000 Aug 25 17:29:06 spla-repro volumio[11072]: [Metrics] WebUI: 6s 586.80ms Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::resetVolumioState Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::getcurrentVolume Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioRetrievevolume Aug 25 17:29:06 spla-repro volumio[11072]: info: Cannot read play queue from file Aug 25 17:29:06 spla-repro volumio[11072]: info: Volumio Network Manager: Network status updated: 1 Aug 25 17:29:06 spla-repro volumio[11158]: Forking 3 albumart workers Aug 25 17:29:06 spla-repro volumio[11072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 25 17:29:06 spla-repro volumio[11072]: Unable to parse: Aug 25 17:29:06 spla-repro volumio[11072]: Simple mixer control 'Master',0 Aug 25 17:29:06 spla-repro volumio[11072]: Capabilities: volume volume-joined Aug 25 17:29:06 spla-repro volumio[11072]: Playback channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Capture channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Limits: 0 - 248 Aug 25 17:29:06 spla-repro volumio[11072]: Mono: 112 [45%] Aug 25 17:29:06 spla-repro volumio[11072]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 25 17:29:06 spla-repro volumio[11072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 25 17:29:06 spla-repro volumio[11072]: info: Received Get System Info Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 17:29:06 spla-repro volumio[11072]: info: Discovery: Getting this device information Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 17:29:06 spla-repro volumio[11072]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 17:29:06 spla-repro volumio[11072]: 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: 3 Aug 25 17:29:06 spla-repro volumio[11072]: Unable to parse: Aug 25 17:29:06 spla-repro volumio[11072]: Simple mixer control 'Master',0 Aug 25 17:29:06 spla-repro volumio[11072]: Capabilities: volume volume-joined Aug 25 17:29:06 spla-repro volumio[11072]: Playback channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Capture channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Limits: 0 - 248 Aug 25 17:29:06 spla-repro volumio[11072]: Mono: 112 [45%] Aug 25 17:29:06 spla-repro volumio[11072]: info: VolumeController:: Volume=undefined Mute =false Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::pushState Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::updateTrackBlock Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrackBlock Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioRetrievevolume Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::setRepeat null single undefined Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::pushState Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::setRandom null Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreStateMachine::pushState Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:06 spla-repro volumio[11072]: info: Setting Device type: Raspberry PI Aug 25 17:29:06 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787671742 101 Aug 25 17:29:06 spla-repro volumio[11072]: 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 Aug 25 17:29:06 spla-repro volumio[11072]: info: Completed loading Core Plugins Aug 25 17:29:06 spla-repro volumio[11072]: info: Preparing to generate the ALSA configuration file Aug 25 17:29:06 spla-repro volumio[11072]: Unable to parse: Aug 25 17:29:06 spla-repro volumio[11072]: Simple mixer control 'Master',0 Aug 25 17:29:06 spla-repro volumio[11072]: Capabilities: volume volume-joined Aug 25 17:29:06 spla-repro volumio[11072]: Playback channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Capture channels: Mono Aug 25 17:29:06 spla-repro volumio[11072]: Limits: 0 - 248 Aug 25 17:29:06 spla-repro volumio[11072]: Mono: 112 [45%] Aug 25 17:29:06 spla-repro volumio[11072]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 25 17:29:06 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:06 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: adding d4caa6fc-95c1-41bd-89e0-c640d24940c4 Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: Found device kuchyna-repro Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: Connecting to remote: 192.168.200.201 Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: adding 284e4a17-0388-4ad0-8157-75a8b67cae8e Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: Found device kupelna-repro Aug 25 17:29:07 spla-repro volumio[11072]: info: Discovery: Connecting to remote: 192.168.200.202 Aug 25 17:29:07 spla-repro volumio[11072]: 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: 5 Aug 25 17:29:07 spla-repro volumio[11072]: 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: 6 Aug 25 17:29:07 spla-repro volumio[11072]: Unable to parse: Aug 25 17:29:07 spla-repro volumio[11072]: Simple mixer control 'Master',0 Aug 25 17:29:07 spla-repro volumio[11072]: Capabilities: volume volume-joined Aug 25 17:29:07 spla-repro volumio[11072]: Playback channels: Mono Aug 25 17:29:07 spla-repro volumio[11072]: Capture channels: Mono Aug 25 17:29:07 spla-repro volumio[11072]: Limits: 0 - 248 Aug 25 17:29:07 spla-repro volumio[11072]: Mono: 112 [45%] Aug 25 17:29:07 spla-repro volumio[11072]: info: VolumeController:: Volume=undefined Mute =false Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreStateMachine::pushState Aug 25 17:29:07 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:07 spla-repro volumio[11072]: info: Listing playlists Aug 25 17:29:07 spla-repro volumio[11072]: info: Listing playlists Aug 25 17:29:07 spla-repro volumio[11072]: info: Asound.conf file unchanged, so no further update is needed Aug 25 17:29:07 spla-repro volumio[11072]: info: Output device has changed, restarting MPD Aug 25 17:29:07 spla-repro volumio[11072]: info: Output device has changed, restarting Shairport Sync Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:07 spla-repro sudo[11215]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 25 17:29:07 spla-repro sudo[11215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:07 spla-repro sudo[11216]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11215]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:07 spla-repro sudo[11216]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 25 17:29:07 spla-repro volumio[11072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:07 spla-repro volumio[11072]: info: ___________ START PLUGINS ___________ Aug 25 17:29:07 spla-repro volumio[11072]: info: ControllerMpd::onStart: Initializing MPD Aug 25 17:29:07 spla-repro volumio[11072]: info: Creating MPD Configuration file Aug 25 17:29:07 spla-repro sudo[11216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:07 spla-repro sudo[11223]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro volumio[11072]: info: [1787671747383] CoreMusicLibrary::Adding element Mediálne servery Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:07 spla-repro sudo[11223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 25 17:29:07 spla-repro sudo[11223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:07 spla-repro systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 25 17:29:07 spla-repro sudo[11227]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11228]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 25 17:29:07 spla-repro volumio[11072]: info: UPNP Browser: Client initialized successfully Aug 25 17:29:07 spla-repro sudo[11228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 25 17:29:07 spla-repro sudo[11228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:07 spla-repro sudo[11227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:07 spla-repro sudo[11228]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:07 spla-repro sudo[11223]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:07 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 25 17:29:07 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 25 17:29:07 spla-repro systemd[1]: mpd.service: Consumed 4.217s CPU time. Aug 25 17:29:07 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 25 17:29:07 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 25 17:29:07 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 25 17:29:07 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 25 17:29:07 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:07.577+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 17:29:07 spla-repro volumio[11072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:07 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 25 17:29:07 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 25 17:29:07 spla-repro volumio[11072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:07 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:07 spla-repro volumio[11072]: info: [1787671747638] CoreMusicLibrary::Adding element Last_100 Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:07 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 25 17:29:07 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:07 spla-repro volumio[11072]: info: [1787671747654] CoreMusicLibrary::Adding element Webradio Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:07 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:07 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 25 17:29:07 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 25 17:29:07 spla-repro volumio[11072]: info: Initializing BBC Radios Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:07 spla-repro volumio[11072]: info: Creating Spotify config file Aug 25 17:29:07 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:07 spla-repro sudo[11243]: root : unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11243]: sudo: unable to resolve host spla-repro: System error Aug 25 17:29:07 spla-repro sudo[11243]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 25 17:29:07 spla-repro sudo[11243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 17:29:07 spla-repro sudo[11243]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:08 spla-repro volumio[11172]: Starting albumart workers Aug 25 17:29:08 spla-repro volumio[11174]: Starting albumart workers Aug 25 17:29:08 spla-repro volumio[11175]: Starting albumart workers Aug 25 17:29:08 spla-repro volumio[11072]: info: Volumio Calling Home Aug 25 17:29:08 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 25 17:29:09 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:09 spla-repro go-librespot[11262]: go-librespot daemon starting... Aug 25 17:29:09 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:09 spla-repro go-librespot[11263]: time="2026-08-25T17:29:09+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:09 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 25 17:29:09 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:09 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:09 spla-repro go-librespot[11263]: time="2026-08-25T17:29:09+02:00" level=info msg="zeroconf server listening on port 36381" Aug 25 17:29:09 spla-repro go-librespot[11263]: time="2026-08-25T17:29:09+02:00" level=info msg="using built-in mDNS responder" Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: Connected to remote: 192.168.200.201 Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: Connected to remote: 192.168.200.202 Aug 25 17:29:09 spla-repro volumio[11072]: info: MPD Permissions set Aug 25 17:29:09 spla-repro volumio[11072]: info: MPD Permissions set Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: adding e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: Found device Spálňa-repro Aug 25 17:29:09 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:09 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:09 spla-repro volumio[11072]: info: Volumio called home Aug 25 17:29:09 spla-repro volumio[11072]: info: Spotify config file written Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: this is already registered, e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 25 17:29:09 spla-repro volumio[11072]: info: Discovery: Found device Spálňa-repro Aug 25 17:29:09 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:09 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:09 spla-repro sudo[11291]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 25 17:29:10 spla-repro sudo[11291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:10 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:10 spla-repro sudo[11291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:10 spla-repro volumio[11072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 25 17:29:10 spla-repro systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro systemd[1]: go-librespot-daemon.service: Killing process 11268 (go-librespot) with signal SIGKILL. Aug 25 17:29:10 spla-repro systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 25 17:29:10 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:10 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:10 spla-repro volumio[11072]: info: No need to fix Spotify hosts Aug 25 17:29:10 spla-repro go-librespot[11298]: go-librespot daemon starting... Aug 25 17:29:10 spla-repro sudo[11291]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="app state loaded" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:10 spla-repro volumio[11072]: info: New Spotify access tokenBQAP_szklH... Aug 25 17:29:10 spla-repro volumio[11072]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 25 17:29:10 spla-repro volumio[11072]: info: Starting Shairport Sync Aug 25 17:29:10 spla-repro volumio[11072]: info: Starting Shairport Sync Aug 25 17:29:10 spla-repro volumio[11072]: info: Starting Shairport Sync Aug 25 17:29:10 spla-repro sudo[11314]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:10 spla-repro sudo[11314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:10 spla-repro sudo[11316]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:10 spla-repro sudo[11314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:10 spla-repro sudo[11318]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:10 spla-repro sudo[11316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:10 spla-repro sudo[11316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:10 spla-repro sudo[11318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:10 spla-repro sudo[11318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:10 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:10 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29: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-gew4.spotify.com:80]" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 25 17:29:10 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Aug 25 17:29:10 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 17:29:10 spla-repro systemd[1]: shairport-sync.service: Consumed 1.930s CPU time. Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=info msg="zeroconf server listening on port 36617" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:10 spla-repro volumio[11072]: SPOTIFY: User informations: {"account_id":"KCva7ZO5Mg","country":"SK","display_name":"Slavomír Predajnoš","email":"slavomir.predajnos@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/4bvaalzmfnjdythud03i86slb"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/4bvaalzmfnjdythud03i86slb","id":"4bvaalzmfnjdythud03i86slb","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85850b6099547eb40fb8c3b7c6","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82850b6099547eb40fb8c3b7c6","width":64}],"product":"premium","type":"user","uri":"spotify:user:4bvaalzmfnjdythud03i86slb"} Aug 25 17:29:10 spla-repro volumio[11072]: info: Spotify Successfully logged in Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:10 spla-repro volumio[11072]: info: [1787671750676] CoreMusicLibrary::Adding element Spotify Aug 25 17:29:10 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:10 spla-repro volumio[11072]: Cannot find translation for source Spotify Aug 25 17:29:10 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 17:29:10 spla-repro sudo[11318]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:10 spla-repro sudo[11316]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:10 spla-repro sudo[11314]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:10 spla-repro volumio[11072]: info: Shairport-Sync Started Aug 25 17:29:10 spla-repro volumio[11072]: Error adding Membership: Error: addMembership EINVAL Aug 25 17:29:10 spla-repro volumio[11072]: info: Shairport-Sync Started Aug 25 17:29:10 spla-repro volumio[11072]: info: Shairport-Sync Started Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="obtained new client token: AAElTee4mk5krcNgxBGZVf3z0FzvyVzpFcJlWwVCgPiSqP3oMOIzQiA79DeqTYkpZyKPNmsINaY2T82ezgFBrfUGj1TCusBAxPvcKMgjJ0g+4rvGR0q81jcKGArToFxyBaflOUOsekiZOpw42iW21nYBlzyleDKEF2YP6SxHvqSxeAONT3tk5KbJfPFpQodMcwv4O+b0gPQUn6C5jOkBQIy4dFiekG6BxOd9o7qrX3N/06V+hnxwcby4kQ==" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=debug msg="completed challenge" Aug 25 17:29:10 spla-repro go-librespot[11304]: time="2026-08-25T17:29:10+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:11 spla-repro go-librespot[11304]: time="2026-08-25T17:29:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:11 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:11 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:12 spla-repro mpd[11258]: 2026-08-25T17:29:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 25 17:29:12 spla-repro systemd[1]: Started mpd.service - Music Player Daemon. Aug 25 17:29:12 spla-repro sudo[11216]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:12 spla-repro sudo[11227]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:12 spla-repro systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 25 17:29:12 spla-repro systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Aug 25 17:29:12 spla-repro systemd[1]: welcome.service: Deactivated successfully. Aug 25 17:29:12 spla-repro systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 25 17:29:12 spla-repro systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 25 17:29:12 spla-repro volumio[11072]: info: Completed starting Core Plugins Aug 25 17:29:12 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:12 spla-repro volumio[11072]: info: ----- MyVolumio plugins startup ---- Aug 25 17:29:12 spla-repro volumio[11072]: info: ------------------------------------------- Aug 25 17:29:12 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 25 17:29:12 spla-repro systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 25 17:29:12 spla-repro welcome[11357]: Resolved ip:[1] 192.168.200.203 Aug 25 17:29:12 spla-repro systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 25 17:29:12 spla-repro systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 25 17:29:12 spla-repro volumio[11072]: error: MPD error: The expression evaluated to a falsy value: Aug 25 17:29:12 spla-repro volumio[11072]: assert.ok(self.idling) Aug 25 17:29:12 spla-repro volumio[11072]: error: The expression evaluated to a falsy value: Aug 25 17:29:12 spla-repro volumio[11072]: assert.ok(self.idling) Aug 25 17:29:12 spla-repro volumio[11072]: error: updateQueue error: null Aug 25 17:29:12 spla-repro volumio[11072]: info: MPD running with PID11258 Aug 25 17:29:12 spla-repro volumio[11072]: ,establishing connection Aug 25 17:29:12 spla-repro volumio[11072]: error: updateQueue error: null Aug 25 17:29:12 spla-repro sudo[11379]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:12 spla-repro sudo[11381]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:12 spla-repro sudo[11379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 17:29:12 spla-repro sudo[11379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:12 spla-repro sudo[11379]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:12 spla-repro sudo[11381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 17:29:12 spla-repro sudo[11381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:12 spla-repro sudo[11381]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:12 spla-repro sudo[11384]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:12 spla-repro sudo[11384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 25 17:29:12 spla-repro sudo[11384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:12 spla-repro sudo[11384]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:12 spla-repro volumio[11072]: info: Upmpdcli Daemon Started Aug 25 17:29:12 spla-repro volumio[11072]: info: Received Get System Info Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 17:29:12 spla-repro volumio[11072]: info: Discovery: Getting this device information Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:12 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 17:29:12 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 17:29:13 spla-repro volumio[11072]: info: go-librespot daemon successfully initialized Aug 25 17:29:13 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:13.594+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 17:29:13 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:13 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:14 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 25 17:29:14 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:14 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:14 spla-repro go-librespot[11388]: go-librespot daemon starting... Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="app state loaded" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=info msg="zeroconf server listening on port 41525" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="obtained new client token: AAGAe9ZsAAFSqaY9TcW/27ZvN5wm0E/F9sDON+s3Wmb9IejG/OVLWCiit1z6NU+4UZMp/qk3/WwPNbr08t/RFdGrJYBHwB2SNqYWyN9uuMGFfbqlpbTugyf/PZRv0zwIzuDIxCamNe9u/qm/OedQkAxMAKpxxEs8nUa07I5rXoatvTawGkPpryqwUCmjKKzgZimHq9+mZPAAdElxM+t+eO+uejbZJAD1rPnn45+ezPVpRqcVrFqLG2Pl7A==" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=debug msg="completed challenge" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:14 spla-repro go-librespot[11389]: time="2026-08-25T17:29:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:14 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:14 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:16 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:16 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:17 spla-repro volumio[11072]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 25 17:29:17 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 25 17:29:17 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:18 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:18 spla-repro go-librespot[11398]: go-librespot daemon starting... Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="app state loaded" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=info msg="zeroconf server listening on port 34523" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="obtained new client token: AAFNDC+1v9oDrIm3MHiW1bc7CKjcBSqMupE9TLLcxFf7i5Rz+Psb6D3WBuFXDZCOF5i10TqiGq31bckhMwGRpYqm24jjlIkqJzvn4J5e60tNyZnHj3f9wPzTQmPPbwWeNadwfxqqLletaoqMGmzrhLJe7wzkRydm3Lnt2xwcRM7S4/dEe1akExFhlXfOXX5R7QMfZnR7qVn8ZplbiGQxNV9IN6w6h7Wq3JYggn4whhgCvzE+TMQ1uloWFw==" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=debug msg="completed challenge" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:18 spla-repro go-librespot[11399]: time="2026-08-25T17:29:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:18 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:18 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:19 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:19 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin bluetooth to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin multiroom to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin metavolumio to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin cd_controller to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 25 17:29:20 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 25 17:29:21 spla-repro volumio[11072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 25 17:29:21 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 25 17:29:21 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:21 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:21 spla-repro volumio[11072]: info: Starting MyVolumio Remote Streaming Endpoints Aug 25 17:29:21 spla-repro volumio[11072]: info: MyVolumio login type: Token Aug 25 17:29:21 spla-repro volumio[11072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 25 17:29:21 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 25 17:29:21 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 25 17:29:21 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:21 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:21 spla-repro go-librespot[11409]: go-librespot daemon starting... Aug 25 17:29:21 spla-repro go-librespot[11410]: time="2026-08-25T17:29:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:21 spla-repro go-librespot[11410]: time="2026-08-25T17:29:21+02:00" level=debug msg="app state loaded" Aug 25 17:29:21 spla-repro go-librespot[11410]: time="2026-08-25T17:29:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=info msg="zeroconf server listening on port 44491" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="obtained new client token: AAGkhEHps5K21Wi2+9+QUDKCyn/NZfmP9y7ZjVwvC1VTNVocW2PQWOeC6ncGoakw7xo7w4s+ji0ZJ8RiRS8ekwNCeEXrfcvXLPq5g37C6aL/tamymys8HaUF0FQTc6CtC/YZshq8oMdTONDgFuPqC8fIxOWGadwdBB1qGivWO07tJSU9JF5vonh55+rM6Ukkf5eMlnGNKOBaNw/n3ZuXxVXgzXKPcyQhE9TSyzsTeat8TZwnGvwM6Ug=" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=debug msg="completed challenge" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:22 spla-repro go-librespot[11410]: time="2026-08-25T17:29:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:22 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:22 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:22 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 25 17:29:22 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 25 17:29:22 spla-repro volumio[11072]: info: Streaming services startup Aug 25 17:29:22 spla-repro volumio[11072]: info: Starting Streaming Daemon Aug 25 17:29:22 spla-repro sudo[11434]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:22 spla-repro volumio[11072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 25 17:29:22 spla-repro sudo[11434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 25 17:29:22 spla-repro sudo[11434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:22 spla-repro sudo[11434]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:22 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:22 spla-repro volumio[11072]: error: Cannot start Volumio Streaming Daemon Aug 25 17:29:22 spla-repro volumio[11072]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 25 17:29:22 spla-repro volumio[11072]: sudo: unable to resolve host spla-repro: System error Aug 25 17:29:22 spla-repro volumio[11072]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 25 17:29:22 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:23 spla-repro volumio[11072]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 25 17:29:23 spla-repro volumio[11072]: info: MyVolumio token set successfully Aug 25 17:29:23 spla-repro volumio[11072]: info: MYVOLUMIO: Adding device Aug 25 17:29:23 spla-repro volumio[11072]: info: MYVOLUMIO: Evaluating Server Aug 25 17:29:23 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:23 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:23 spla-repro volumio[11072]: info: Listing playlists Aug 25 17:29:23 spla-repro volumio[11072]: info: Listing playlists Aug 25 17:29:24 spla-repro volumio[11072]: info: MyVolumio status changed Aug 25 17:29:24 spla-repro volumio[11072]: info: Streaming services startup Aug 25 17:29:24 spla-repro volumio[11072]: info: Starting Streaming Daemon Aug 25 17:29:24 spla-repro volumio[11072]: info: Removing browser output: myVolumio user plan is not superstar Aug 25 17:29:24 spla-repro volumio[11072]: info: Removing audio output: Aug 25 17:29:24 spla-repro volumio[11072]: info: Stoppping Tunnel 1 Aug 25 17:29:24 spla-repro sudo[11461]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:24 spla-repro sudo[11461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 25 17:29:24 spla-repro sudo[11461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:24 spla-repro sudo[11461]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:24 spla-repro sudo[11464]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:24 spla-repro volumio[11072]: error: Cannot start Volumio Streaming Daemon Aug 25 17:29:24 spla-repro volumio[11072]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 25 17:29:24 spla-repro volumio[11072]: sudo: unable to resolve host spla-repro: System error Aug 25 17:29:24 spla-repro volumio[11072]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 25 17:29:24 spla-repro sudo[11464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 25 17:29:24 spla-repro sudo[11464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 25 17:29:24 spla-repro sudo[11464]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:24 spla-repro volumio[11072]: info: Remote SSH Stopped Aug 25 17:29:24 spla-repro volumio[11072]: info: Setting Geolocation for MyVolumio to eu6 Aug 25 17:29:24 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:24 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:24 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:24 spla-repro volumio[11072]: info: Successfully Added MyVolumio device Aug 25 17:29:25 spla-repro volumio[11072]: info: Updating MyVolumio device info Aug 25 17:29:25 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:25 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:25 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:25 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 25 17:29:25 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:25 spla-repro volumio[11072]: info: Successfully Updated MyVolumio device Aug 25 17:29:25 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:25 spla-repro go-librespot[11466]: go-librespot daemon starting... Aug 25 17:29:25 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:25 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:25 spla-repro go-librespot[11467]: time="2026-08-25T17:29:25+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:25 spla-repro go-librespot[11467]: time="2026-08-25T17:29:25+02:00" level=debug msg="app state loaded" Aug 25 17:29:25 spla-repro go-librespot[11467]: time="2026-08-25T17:29:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=info msg="zeroconf server listening on port 45693" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="obtained new client token: AAGZd+2ro8jUcy2v5dq6HZZItpDV5vH9zPMCbIBFj0/+EwhxZ8D7Yf985YIsLUoOFfDuMr2kJwxJTlHVD2GajLeWbdBOkXcE2r2ig0dzma0kK2N0cv64aR15xSpyl06Uo9ET6/mDcn7lObBbcuJFGnH4kcBGnyt/Q3knUalH7DL5KctqdZvvKlNQVSbvH2mQnpsrcDYxsgWYo+CbRfmbKLobf3jrY65a8JV3hsxvBcmHokidzg3FPlg=" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=debug msg="completed challenge" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:26 spla-repro go-librespot[11467]: time="2026-08-25T17:29:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:26 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:26 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:28 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:28 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:29 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 25 17:29:29 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:29 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:29 spla-repro go-librespot[11476]: go-librespot daemon starting... Aug 25 17:29:29 spla-repro go-librespot[11477]: time="2026-08-25T17:29:29+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:29 spla-repro go-librespot[11477]: time="2026-08-25T17:29:29+02:00" level=debug msg="app state loaded" Aug 25 17:29:29 spla-repro go-librespot[11477]: time="2026-08-25T17:29:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=info msg="zeroconf server listening on port 36199" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="obtained new client token: AAHHQWPm//voE1UsbNF1QjC/K7HCdrrmO2yfxMaaEDLhDJYaSXOnLfQlCrF2hxKuI3D7RrRpBD59XmGJvr6xOknu4xT2C5z74CT2czYBXMw7ZyQJ0C1i45v4mz65cRv+EaTMM4L3PwPer7PMq0Ci9r5qkkFoHcEt9iXFkwff2YiNeag6DiUVjhHJana/j54N/EHq7pLCI/WgV8vQcLVFwvtN2/W6QFn6zjzHHDfxRfmi/+qdcSumm/E=" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=debug msg="completed challenge" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:30 spla-repro go-librespot[11477]: time="2026-08-25T17:29:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:30 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:30 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:31 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:31 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:33 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 25 17:29:33 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:33 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:33 spla-repro go-librespot[11501]: go-librespot daemon starting... Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=debug msg="app state loaded" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:33 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:33 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=info msg="zeroconf server listening on port 44123" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:33 spla-repro go-librespot[11502]: time="2026-08-25T17:29:33+02:00" level=debug msg="obtained new client token: AAFzn4DBZjl12LJD5Vmq3FbqZJXmBlBWxLGKZ6arSZOX95DgG4BxqibKrtjnAqTWPjAArYOwrQDv+zBOZYB2L9+3EVKz9D8PSWWl7ePTxQVnzmjcow3D8Rf7rTJP4qAjDxLJL0ypvR4pD7xByMhOdhr8w2geSbqoXD3s0kpZ0GuawTkZ8rhcmxh3YAGqG0UedvUYqsjZLea8UhLgOpHqSjUdgDPZDAmmW5UhLab9awjQTkc3Om/n4JAa9A==" Aug 25 17:29:34 spla-repro go-librespot[11502]: time="2026-08-25T17:29:34+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:34 spla-repro go-librespot[11502]: time="2026-08-25T17:29:34+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:34 spla-repro go-librespot[11502]: time="2026-08-25T17:29:34+02:00" level=debug msg="completed challenge" Aug 25 17:29:34 spla-repro go-librespot[11502]: time="2026-08-25T17:29:34+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:34 spla-repro go-librespot[11502]: time="2026-08-25T17:29:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:34 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:34 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:34 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:34 spla-repro volumio[11072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:36 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 25 17:29:36 spla-repro volumio[11072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 25 17:29:36 spla-repro volumio[11072]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:36 spla-repro volumio[11072]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:37 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 25 17:29:37 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:37 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:37 spla-repro go-librespot[11511]: go-librespot daemon starting... Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="app state loaded" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:37 spla-repro volumio[11072]: info: Initializing connection to go-librespot Websocket Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="new websocket client" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=info msg="zeroconf server listening on port 43287" Aug 25 17:29:37 spla-repro volumio[11072]: info: Connection to go-librespot Websocket established Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="obtained new client token: AAGtkw5KRUOew9QVpt3eFDa6cVkyi/K11hp2r2rhBrLs6T5jiaEh51ifvEVEETwQ3Cn7u6ERvrC2RlfMN+cEwf+L9BhSTqCAmJP6yApUY7TmW2HxZUPmXHh93M+rQgYuNlFR86+4Bv5yjwcOpf0yY+kZzFAZ3W/EN8cSLCyRsVDgGKcCPrxzFfLmzk+bP/shpO0jvVaWueTX/0upcuZtcoDbSHUh4l9CO8kCMUCj3Q0nhR9HFIxi8OLLtA==" Aug 25 17:29:37 spla-repro go-librespot[11512]: time="2026-08-25T17:29:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:38 spla-repro go-librespot[11512]: time="2026-08-25T17:29:38+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:38 spla-repro go-librespot[11512]: time="2026-08-25T17:29:38+02:00" level=debug msg="completed challenge" Aug 25 17:29:38 spla-repro go-librespot[11512]: time="2026-08-25T17:29:38+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:38 spla-repro go-librespot[11512]: time="2026-08-25T17:29:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:38 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:38 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:38 spla-repro volumio[11072]: info: Connection to go-librespot Websocket closed Aug 25 17:29:38 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:38 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:38 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 25 17:29:38 spla-repro volumio-remote-updater[725]: Test mode disabled Aug 25 17:29:38 spla-repro volumio-remote-updater[725]: Alpha mode disabled Aug 25 17:29:38 spla-repro volumio-remote-updater[725]: Alpha legacy test mode disabled Aug 25 17:29:38 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 25 17:29:38 spla-repro volumio[11072]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 25 17:29:38 spla-repro volumio[11072]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 25 17:29:40 spla-repro volumio[11072]: info: Getting Spotify volume Aug 25 17:29:40 spla-repro volumio[11072]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:29:40 spla-repro volumio[11072]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:29:40 spla-repro volumio[11072]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 25 17:29:40 spla-repro volumio[11072]: errno: -111, Aug 25 17:29:40 spla-repro volumio[11072]: code: 'ECONNREFUSED', Aug 25 17:29:40 spla-repro volumio[11072]: syscall: 'connect', Aug 25 17:29:40 spla-repro volumio[11072]: address: '127.0.0.1', Aug 25 17:29:40 spla-repro volumio[11072]: port: 9879, Aug 25 17:29:40 spla-repro volumio[11072]: response: undefined Aug 25 17:29:40 spla-repro volumio[11072]: } Aug 25 17:29:40 spla-repro volumio[11072]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:29:41 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 25 17:29:41 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:41 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:41 spla-repro go-librespot[11537]: go-librespot daemon starting... Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="app state loaded" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=info msg="zeroconf server listening on port 33843" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:41 spla-repro sudo[11549]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:41 spla-repro sudo[11549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 17:28' Aug 25 17:29:41 spla-repro sudo[11549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="obtained new client token: AAE+b/RcmT57OC9JUOc9C9wCPoWOYjb8wgA2DCA1ZKxLRO2aly6VdqklJbcIjXv/Z2yjYXl5hEfAo8YAzvw7OdeN0EjPNBqgoXK0jCaeujze2VZ9w0hPLyy0oBjLWcI2t+wu5erneIlfh25Tho8hM2mL56g69EDfqEgUXW2bPdhigb53HxA5Wlg3AG82NUIHRrzIVPRjOTC3wVWQBBOh0wKnmGQ1ItDw2eHfk23MFH0ck2tCkdJXAesjCw==" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=debug msg="completed challenge" Aug 25 17:29:41 spla-repro go-librespot[11538]: time="2026-08-25T17:29:41+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:41 spla-repro sudo[11549]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:41 spla-repro volumio[11072]: sudo: unable to resolve host spla-repro: System error Aug 25 17:29:41 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:41.998+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 25 17:29:42 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 25 17:29:42 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 25 17:29:42 spla-repro systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:42 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:42.003+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 25 17:29:42 spla-repro go-librespot[11538]: time="2026-08-25T17:29:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:42 spla-repro systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 25 17:29:42 spla-repro systemd[1]: volumio.service: Consumed 30.182s CPU time. Aug 25 17:29:42 spla-repro systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 25 17:29:42 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:42 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:42 spla-repro systemd[1]: dynamicswap.service: Deactivated successfully. Aug 25 17:29:42 spla-repro systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5618. Aug 25 17:29:42 spla-repro systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 25 17:29:42 spla-repro systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 25 17:29:42 spla-repro systemd[1]: volumio.service: Consumed 30.182s CPU time. Aug 25 17:29:42 spla-repro systemd[1]: Started volumio.service - Volumio Backend Module. Aug 25 17:29:42 spla-repro systemd[1]: dynamicswap.service: Deactivated successfully. Aug 25 17:29:43 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:43.004+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 25 17:29:44 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:44 spla-repro volumio[11561]: info: ----- Volumio3 ---- Aug 25 17:29:44 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:44 spla-repro volumio[11561]: info: ----- System startup ---- Aug 25 17:29:44 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:45 spla-repro volumio[11561]: info: MYVOLUMIO Environment detected Aug 25 17:29:45 spla-repro volumio[11561]: info: Plugin folders cleanup Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning into folder /volumio/app/plugins/ Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category audio_interface Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category miscellanea Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category music_service Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category plugins.json Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category system_controller Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category user_interface Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning into folder /data/plugins/ Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category audio_interface Aug 25 17:29:45 spla-repro volumio[11561]: info: Scanning category music_service Aug 25 17:29:45 spla-repro volumio[11561]: info: Plugin folders cleanup completed Aug 25 17:29:45 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:45 spla-repro volumio[11561]: info: ----- Core plugins startup ---- Aug 25 17:29:45 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:45 spla-repro volumio[11561]: info: Loading plugins from folder /volumio/app/plugins/ Aug 25 17:29:45 spla-repro volumio[11561]: info: Adding plugin upnp to MyMusic Plugins Aug 25 17:29:45 spla-repro volumio[11561]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 25 17:29:45 spla-repro volumio[11561]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 25 17:29:45 spla-repro volumio[11561]: info: Loading plugins from folder /data/plugins/ Aug 25 17:29:45 spla-repro volumio[11561]: info: Loading plugin "system"... Aug 25 17:29:45 spla-repro volumio[11561]: info: Loading plugin "appearance"... Aug 25 17:29:45 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 25 17:29:45 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:45 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:45 spla-repro go-librespot[11588]: go-librespot daemon starting... Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="app state loaded" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=info msg="zeroconf server listening on port 46065" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="obtained new client token: AAGZwGrfI0pQxA9G7DCdTPz16mlYBm0kfYtqAhtg9oqXagla7pRxa9BkWZhHt+9ok2t0QDrseDvgrfoizbsABtOf25HFR2f3SYhx7sOq63tKuBWMwqOvFgrG/pj27CO1C5qnpu6q4JpPY9AYiFAKPHWcMFf7WwMzMWdF3j7+2yTNpBEMjzYqb32ebnUAK7Lr5AVBPysvoL5DL/QUNU6qSLSBX8LOGx+lC1Wkl/Jr+pSkKty6IUgcyot85A==" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=debug msg="completed challenge" Aug 25 17:29:45 spla-repro go-librespot[11589]: time="2026-08-25T17:29:45+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:46 spla-repro go-librespot[11589]: time="2026-08-25T17:29:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:46 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:46 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "network"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Refreshing Cached IP Addresses Aug 25 17:29:46 spla-repro sudo[11599]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:46 spla-repro sudo[11601]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:46 spla-repro sudo[11599]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 17:29:46 spla-repro sudo[11601]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "services"... Aug 25 17:29:46 spla-repro sudo[11601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:46 spla-repro sudo[11599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "volumio5onboarding"... Aug 25 17:29:46 spla-repro sudo[11601]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:46 spla-repro sudo[11599]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:46 spla-repro sudo[11608]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "alsa_controller"... Aug 25 17:29:46 spla-repro sudo[11608]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 25 17:29:46 spla-repro sudo[11608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:46 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "wizard"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "networkfs"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Starting Udev Watcher for removable devices Aug 25 17:29:46 spla-repro volumio[11561]: info: Ignoring mount for partition: boot Aug 25 17:29:46 spla-repro volumio[11561]: info: Ignoring mount for partition: volumio Aug 25 17:29:46 spla-repro volumio[11561]: info: Ignoring mount for partition: volumio_data Aug 25 17:29:46 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "volumio_command_line_client"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "upnp"... Aug 25 17:29:46 spla-repro volumio[11561]: info: [1787671786533] Starting Upmpd Daemon Aug 25 17:29:46 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "my_music"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "mpd"... Aug 25 17:29:46 spla-repro volumio[11561]: info: Loading plugin "upnp_browser"... Aug 25 17:29:47 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:46] [connect] Successful connection Aug 25 17:29:47 spla-repro sudo[11608]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:48 spla-repro volumio[11561]: info: Starting UPNP Browser Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "alarm-clock"... Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "airplay_emulation"... Aug 25 17:29:48 spla-repro volumio[11561]: info: Starting Shairport Sync Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "last_100"... Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "webradio"... Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "i2s_dacs"... Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "volumiodiscovery"... Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** For more information see Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:48 spla-repro volumio[11561]: *** WARNING *** For more information see Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** For more information see Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 25 17:29:48 spla-repro node[11561]: *** WARNING *** For more information see Aug 25 17:29:48 spla-repro volumio[11561]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 25 17:29:48 spla-repro volumio[11561]: info: Discovery: Started advertising with name: Spálňa-repro Aug 25 17:29:48 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 25 17:29:48 spla-repro volumio[11561]: info: Loading plugin "spop"... Aug 25 17:29:49 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 25 17:29:49 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:49 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:49 spla-repro go-librespot[11634]: go-librespot daemon starting... Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="app state loaded" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=info msg="zeroconf server listening on port 33243" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="obtained new client token: AAGPADHG4mFvoTwW0YVz8M/X6pNtoaSswPk3yQSq9ifYSRuV9d9nMcBkaLtb8AUpQ5F0t10GuuyEg6rsQLBBlnq5dRBG/ghEofaG/tzloKZmEb6Fat0k/tI4+eCnFdjiWH7cIu+Cpqokp701HUGFoeb5/T0+pQ8TlMYzZTd1dr+xMpmA9j6xlYGGxJlV8rcXzxvnERW8nqyLpL7wOvNyMTwg+25RSbGs9yOSBLj1rnSEU8j+oYy5Fwz4Mw==" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=debug msg="completed challenge" Aug 25 17:29:49 spla-repro volumio[11561]: info: Loading plugin "outputs"... Aug 25 17:29:49 spla-repro volumio[11561]: info: Loading plugin "albumart"... Aug 25 17:29:49 spla-repro go-librespot[11635]: time="2026-08-25T17:29:49+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:49 spla-repro volumio[11561]: info: Plugin example_plugin is not enabled Aug 25 17:29:49 spla-repro volumio[11561]: info: Loading plugin "inputs"... Aug 25 17:29:49 spla-repro volumio[11561]: info: Loading plugin "updater_comm"... Aug 25 17:29:50 spla-repro go-librespot[11635]: time="2026-08-25T17:29:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:50 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:50 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:50 spla-repro volumio[11561]: info: Plugin mpdemulation is not enabled Aug 25 17:29:50 spla-repro volumio[11561]: info: Loading plugin "rest_api"... Aug 25 17:29:50 spla-repro volumio[11561]: info: Loading plugin "websocket"... Aug 25 17:29:50 spla-repro volumio[11561]: info: Starting Socket.io Server version 1.7.4 Aug 25 17:29:50 spla-repro volumio[11561]: info: Plugin fusiondsp is not enabled Aug 25 17:29:50 spla-repro volumio[11561]: info: Loading i18n strings for locale sk Aug 25 17:29:50 spla-repro volumio[11561]: Updating browse sources language Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::initPlayerControls Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: Express server listening on port 3000 Aug 25 17:29:50 spla-repro volumio[11561]: [Metrics] WebUI: 6s 564.99ms Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::resetVolumioState Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::getcurrentVolume Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioRetrievevolume Aug 25 17:29:50 spla-repro volumio[11561]: info: Cannot read play queue from file Aug 25 17:29:50 spla-repro volumio[11561]: info: Volumio Network Manager: Network status updated: 1 Aug 25 17:29:50 spla-repro volumio[11561]: Unable to parse: Aug 25 17:29:50 spla-repro volumio[11561]: Simple mixer control 'Master',0 Aug 25 17:29:50 spla-repro volumio[11561]: Capabilities: volume volume-joined Aug 25 17:29:50 spla-repro volumio[11561]: Playback channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Capture channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Limits: 0 - 248 Aug 25 17:29:50 spla-repro volumio[11561]: Mono: 112 [45%] Aug 25 17:29:50 spla-repro volumio[11561]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:50 spla-repro volumio[11644]: Forking 3 albumart workers Aug 25 17:29:50 spla-repro volumio[11561]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 25 17:29:50 spla-repro volumio[11561]: Unable to parse: Aug 25 17:29:50 spla-repro volumio[11561]: Simple mixer control 'Master',0 Aug 25 17:29:50 spla-repro volumio[11561]: Capabilities: volume volume-joined Aug 25 17:29:50 spla-repro volumio[11561]: Playback channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Capture channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Limits: 0 - 248 Aug 25 17:29:50 spla-repro volumio[11561]: Mono: 112 [45%] Aug 25 17:29:50 spla-repro volumio[11561]: info: VolumeController:: Volume=undefined Mute =false Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::pushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::updateTrackBlock Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrackBlock Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioRetrievevolume Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:50 spla-repro volumio[11561]: 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: 1 Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::setRepeat null single undefined Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::pushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::setRandom null Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::pushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:50 spla-repro volumio[11561]: info: Setting Device type: Raspberry PI Aug 25 17:29:50 spla-repro volumio[11561]: info: Listing playlists Aug 25 17:29:50 spla-repro volumio[11561]: info: Listing playlists Aug 25 17:29:50 spla-repro volumio[11561]: verbose: New Socket.io Connection to 192.168.200.203:3000 from 192.168.200.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 25 17:29:50 spla-repro volumio[11561]: info: Completed loading Core Plugins Aug 25 17:29:50 spla-repro volumio[11561]: info: Preparing to generate the ALSA configuration file Aug 25 17:29:50 spla-repro volumio[11561]: Unable to parse: Aug 25 17:29:50 spla-repro volumio[11561]: Simple mixer control 'Master',0 Aug 25 17:29:50 spla-repro volumio[11561]: Capabilities: volume volume-joined Aug 25 17:29:50 spla-repro volumio[11561]: Playback channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Capture channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Limits: 0 - 248 Aug 25 17:29:50 spla-repro volumio[11561]: Mono: 112 [45%] Aug 25 17:29:50 spla-repro volumio[11561]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Aug 25 17:29:50 spla-repro volumio-remote-updater[725]: [2026-08-25 17:29:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787671786 101 Aug 25 17:29:50 spla-repro volumio[11561]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 25 17:29:50 spla-repro volumio[11561]: 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: 4 Aug 25 17:29:50 spla-repro volumio[11561]: Unable to parse: Aug 25 17:29:50 spla-repro volumio[11561]: Simple mixer control 'Master',0 Aug 25 17:29:50 spla-repro volumio[11561]: Capabilities: volume volume-joined Aug 25 17:29:50 spla-repro volumio[11561]: Playback channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Capture channels: Mono Aug 25 17:29:50 spla-repro volumio[11561]: Limits: 0 - 248 Aug 25 17:29:50 spla-repro volumio[11561]: Mono: 112 [45%] Aug 25 17:29:50 spla-repro volumio[11561]: info: VolumeController:: Volume=undefined Mute =false Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreStateMachine::pushState Aug 25 17:29:50 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:50 spla-repro volumio[11561]: info: CoreCommandRouter::volumioPushState Aug 25 17:29:50 spla-repro volumio[11561]: info: Discovery: adding 284e4a17-0388-4ad0-8157-75a8b67cae8e Aug 25 17:29:50 spla-repro volumio[11561]: info: Discovery: Found device kupelna-repro Aug 25 17:29:51 spla-repro volumio[11561]: info: Discovery: Connecting to remote: 192.168.200.202 Aug 25 17:29:51 spla-repro volumio[11561]: info: Discovery: adding d4caa6fc-95c1-41bd-89e0-c640d24940c4 Aug 25 17:29:51 spla-repro volumio[11561]: info: Discovery: Found device kuchyna-repro Aug 25 17:29:51 spla-repro volumio[11561]: info: Discovery: Connecting to remote: 192.168.200.201 Aug 25 17:29:51 spla-repro volumio[11561]: 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: 5 Aug 25 17:29:51 spla-repro volumio[11561]: 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: 6 Aug 25 17:29:51 spla-repro volumio[11561]: info: Asound.conf file unchanged, so no further update is needed Aug 25 17:29:51 spla-repro volumio[11561]: info: Output device has changed, restarting MPD Aug 25 17:29:51 spla-repro volumio[11561]: info: Output device has changed, restarting Shairport Sync Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:51 spla-repro sudo[11700]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro volumio[11561]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:51 spla-repro sudo[11700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 25 17:29:51 spla-repro sudo[11700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:51 spla-repro sudo[11700]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:51 spla-repro sudo[11704]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro volumio[11561]: info: ___________ START PLUGINS ___________ Aug 25 17:29:51 spla-repro sudo[11704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 25 17:29:51 spla-repro sudo[11704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:51 spla-repro volumio[11561]: info: ControllerMpd::onStart: Initializing MPD Aug 25 17:29:51 spla-repro volumio[11561]: info: Creating MPD Configuration file Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:51 spla-repro volumio[11561]: info: [1787671791278] CoreMusicLibrary::Adding element Mediálne servery Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:51 spla-repro sudo[11712]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 25 17:29:51 spla-repro sudo[11711]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro sudo[11714]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro volumio[11561]: info: UPNP Browser: Client initialized successfully Aug 25 17:29:51 spla-repro sudo[11712]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 25 17:29:51 spla-repro sudo[11712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:51 spla-repro sudo[11714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 25 17:29:51 spla-repro sudo[11714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:51 spla-repro sudo[11711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 25 17:29:51 spla-repro sudo[11712]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:51 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 25 17:29:51 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 25 17:29:51 spla-repro systemd[1]: mpd.service: Consumed 4.355s CPU time. Aug 25 17:29:51 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:51 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 25 17:29:51 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 25 17:29:51 spla-repro sudo[11711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:51 spla-repro volumio[11561]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:51 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 25 17:29:51 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 25 17:29:51 spla-repro volumio[11561]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:51 spla-repro volumio[11561]: info: [1787671791552] CoreMusicLibrary::Adding element Last_100 Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:51 spla-repro systemd[1]: mpd.service: Deactivated successfully. Aug 25 17:29:51 spla-repro volumio[11561]: info: [1787671791569] CoreMusicLibrary::Adding element Webradio Aug 25 17:29:51 spla-repro systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:51 spla-repro systemd[1]: mpd.socket: Deactivated successfully. Aug 25 17:29:51 spla-repro systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 25 17:29:51 spla-repro systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:51 spla-repro volumio[11561]: info: Initializing BBC Radios Aug 25 17:29:51 spla-repro systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 25 17:29:51 spla-repro systemd[1]: Starting mpd.service - Music Player Daemon... Aug 25 17:29:51 spla-repro sudo[11711]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:51 spla-repro volumio[11561]: info: Creating Spotify config file Aug 25 17:29:51 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:51 spla-repro sudo[11733]: root : unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro sudo[11733]: sudo: unable to resolve host spla-repro: System error Aug 25 17:29:51 spla-repro sudo[11733]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 25 17:29:51 spla-repro sudo[11733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 17:29:51 spla-repro sudo[11733]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:52 spla-repro volumio[11561]: info: Volumio Calling Home Aug 25 17:29:52 spla-repro volumio[11661]: Starting albumart workers Aug 25 17:29:52 spla-repro volumio[11662]: Starting albumart workers Aug 25 17:29:52 spla-repro volumio[11659]: Starting albumart workers Aug 25 17:29:52 spla-repro volumio[11561]: info: Discovery: adding e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 25 17:29:52 spla-repro volumio[11561]: info: Discovery: Found device Spálňa-repro Aug 25 17:29:52 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:52 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:52 spla-repro volumio[11561]: info: MPD Permissions set Aug 25 17:29:52 spla-repro volumio[11561]: info: MPD Permissions set Aug 25 17:29:52 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 25 17:29:52 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:52 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:52 spla-repro volumio[11561]: info: Discovery: Connected to remote: 192.168.200.202 Aug 25 17:29:52 spla-repro volumio[11561]: info: Volumio called home Aug 25 17:29:52 spla-repro volumio[11561]: info: Spotify config file written Aug 25 17:29:53 spla-repro volumio[11561]: info: Discovery: this is already registered, e4ea6882-b508-4641-a5d5-383d83cd05b4 Aug 25 17:29:53 spla-repro volumio[11561]: info: Discovery: Found device Spálňa-repro Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:53 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:53 spla-repro sudo[11749]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:53 spla-repro sudo[11749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 25 17:29:53 spla-repro sudo[11749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:53 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 25 17:29:53 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:53 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:53 spla-repro go-librespot[11751]: go-librespot daemon starting... Aug 25 17:29:53 spla-repro systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 25 17:29:53 spla-repro systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 25 17:29:53 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:53 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:53 spla-repro go-librespot[11753]: go-librespot daemon starting... Aug 25 17:29:53 spla-repro sudo[11749]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:53 spla-repro volumio[11561]: info: Discovery: Connected to remote: 192.168.200.201 Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=debug msg="app state loaded" Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 25 17:29:53 spla-repro volumio[11561]: info: No need to fix Spotify hosts Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 25 17:29:53 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:53 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=info msg="zeroconf server listening on port 38959" Aug 25 17:29:53 spla-repro go-librespot[11754]: time="2026-08-25T17:29:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:54 spla-repro volumio[11561]: 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: 6 Aug 25 17:29:54 spla-repro volumio[11561]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 25 17:29:54 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:54 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=debug msg="obtained new client token: AAFWIJOWf1dtTmkJggjEgWWnrLCBXuip7/rwY2u856hBYhsr1HepGEUHISDmW3ZeYGzxjxyXPpkBEBNWdEEaQzARxyCBqPToy55z2UbwRCglB/v7VO4v94yK85rmM2S9FPf77eTDZjkxMXCNRXPxlGquN3RIXK9u8GZn2HrYY4MCf+KrykRiLuXHl6Mhcqny782VXiwg7Y4Ppan1pwaH21YaaA4jnlpn12+80AJKkYWRI20jGsD9hY4=" Aug 25 17:29:54 spla-repro volumio[11561]: info: New Spotify access tokenBQAjhVEAXl... Aug 25 17:29:54 spla-repro volumio[11561]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:54 spla-repro volumio[11561]: info: Starting Shairport Sync Aug 25 17:29:54 spla-repro volumio[11561]: info: Starting Shairport Sync Aug 25 17:29:54 spla-repro volumio[11561]: info: Starting Shairport Sync Aug 25 17:29:54 spla-repro sudo[11792]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:54 spla-repro sudo[11794]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:54 spla-repro sudo[11792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:54 spla-repro sudo[11792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=debug msg="completed challenge" Aug 25 17:29:54 spla-repro sudo[11794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:54 spla-repro sudo[11794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:54 spla-repro sudo[11796]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:54 spla-repro sudo[11796]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 25 17:29:54 spla-repro sudo[11796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 25 17:29:54 spla-repro systemd[1]: shairport-sync.service: Deactivated successfully. Aug 25 17:29:54 spla-repro systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 17:29:54 spla-repro systemd[1]: shairport-sync.service: Consumed 1.931s CPU time. Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro go-librespot[11754]: time="2026-08-25T17:29:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:54 spla-repro systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 17:29:54 spla-repro sudo[11792]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:54 spla-repro sudo[11794]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:54 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:29:54 spla-repro sudo[11796]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:54 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:29:54 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:29:54 spla-repro volumio[11561]: info: Shairport-Sync Started Aug 25 17:29:54 spla-repro volumio[11561]: Error adding Membership: Error: addMembership EINVAL Aug 25 17:29:54 spla-repro volumio[11561]: info: Shairport-Sync Started Aug 25 17:29:54 spla-repro volumio[11561]: info: Shairport-Sync Started Aug 25 17:29:54 spla-repro volumio[11561]: SPOTIFY: User informations: {"account_id":"KCva7ZO5Mg","country":"SK","display_name":"Slavomír Predajnoš","email":"slavomir.predajnos@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/4bvaalzmfnjdythud03i86slb"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/4bvaalzmfnjdythud03i86slb","id":"4bvaalzmfnjdythud03i86slb","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85850b6099547eb40fb8c3b7c6","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82850b6099547eb40fb8c3b7c6","width":64}],"product":"premium","type":"user","uri":"spotify:user:4bvaalzmfnjdythud03i86slb"} Aug 25 17:29:54 spla-repro volumio[11561]: info: Spotify Successfully logged in Aug 25 17:29:54 spla-repro volumio[11561]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 25 17:29:54 spla-repro volumio[11561]: info: [1787671794562] CoreMusicLibrary::Adding element Spotify Aug 25 17:29:54 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:29:54 spla-repro volumio[11561]: Cannot find translation for source Spotify Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:54 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:55 spla-repro volumio[11561]: 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: 7 Aug 25 17:29:56 spla-repro mpd[11744]: 2026-08-25T17:29:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 25 17:29:56 spla-repro systemd[1]: Started mpd.service - Music Player Daemon. Aug 25 17:29:56 spla-repro sudo[11704]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:56 spla-repro sudo[11714]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:56 spla-repro volumio[11561]: info: Completed starting Core Plugins Aug 25 17:29:56 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:56 spla-repro volumio[11561]: info: ----- MyVolumio plugins startup ---- Aug 25 17:29:56 spla-repro volumio[11561]: info: ------------------------------------------- Aug 25 17:29:56 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 25 17:29:56 spla-repro volumio[11561]: error: MPD error: The expression evaluated to a falsy value: Aug 25 17:29:56 spla-repro volumio[11561]: assert.ok(self.idling) Aug 25 17:29:56 spla-repro volumio[11561]: error: The expression evaluated to a falsy value: Aug 25 17:29:56 spla-repro volumio[11561]: assert.ok(self.idling) Aug 25 17:29:56 spla-repro volumio[11561]: info: MPD running with PID11744 Aug 25 17:29:56 spla-repro volumio[11561]: ,establishing connection Aug 25 17:29:56 spla-repro volumio[11561]: error: updateQueue error: null Aug 25 17:29:56 spla-repro volumio[11561]: error: updateQueue error: null Aug 25 17:29:56 spla-repro sudo[11834]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:56 spla-repro sudo[11834]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 17:29:56 spla-repro sudo[11834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:56 spla-repro sudo[11836]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:56 spla-repro sudo[11834]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:56 spla-repro sudo[11836]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 17:29:56 spla-repro sudo[11836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:56 spla-repro sudo[11839]: volumio : unable to resolve host spla-repro: System error Aug 25 17:29:56 spla-repro sudo[11836]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:56 spla-repro sudo[11839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 25 17:29:56 spla-repro sudo[11839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:29:56 spla-repro sudo[11839]: pam_unix(sudo:session): session closed for user root Aug 25 17:29:56 spla-repro volumio[11561]: info: Upmpdcli Daemon Started Aug 25 17:29:57 spla-repro volumio[11561]: info: go-librespot daemon successfully initialized Aug 25 17:29:57 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 25 17:29:57 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:57 spla-repro volumio5-onboarding[16326]: time=2026-08-25T17:29:57.489+02:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Aug 25 17:29:57 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:29:57 spla-repro go-librespot[11842]: go-librespot daemon starting... Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=debug msg="app state loaded" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=info msg="zeroconf server listening on port 38953" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:29:57 spla-repro go-librespot[11843]: time="2026-08-25T17:29:57+02:00" level=debug msg="obtained new client token: AAEVjFJ6X9HW9nNoUzVvj63zGbh3Swqlii6QzPcUUT7eXZkE+vMTRRfD8qyPLUuIGiSwmALXUjRMvNjNEmLJMG8l5sT7+dCdmsdsVSkggwhv10ftYzTz/b0RuYMEtwDhQZ45Ky5uwbwt4cdGTTBLKOi2wZNxz9x5uP6+dQU0pK/BSu7Uum+hlKb4+Oo4OJv+0X3Po9HuFdZx/A6OOkQzLCeHVVtHho/ymiDqVC+kXfuJHrMouP/zKPTwZQ==" Aug 25 17:29:58 spla-repro go-librespot[11843]: time="2026-08-25T17:29:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:29:59 spla-repro go-librespot[11843]: time="2026-08-25T17:29:59+02:00" level=debug msg="completed keyexchange" Aug 25 17:29:59 spla-repro go-librespot[11843]: time="2026-08-25T17:29:59+02:00" level=debug msg="completed challenge" Aug 25 17:29:59 spla-repro go-librespot[11843]: time="2026-08-25T17:29:59+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:29:59 spla-repro go-librespot[11843]: time="2026-08-25T17:29:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:29:59 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:29:59 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:30:00 spla-repro volumio[11561]: info: Initializing connection to go-librespot Websocket Aug 25 17:30:00 spla-repro volumio[11561]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 25 17:30:01 spla-repro volumio[11561]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 25 17:30:02 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 25 17:30:02 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:30:02 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:30:02 spla-repro go-librespot[11853]: go-librespot daemon starting... Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=debug msg="app state loaded" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=info msg="zeroconf server listening on port 39965" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=debug msg="obtained new client token: AAGm64j2MbvXSSnW1FJEjn1PeLIXBhmh00RUKVUlJ+no+aaBPMhR5SYY3/Oi114kx30UrepFgxD5W96giWkpD7DEYvw1MjbIrK+zF19H5DDETDdLQvoumAlXH8NTcL8Nwy0UqIOetB4ZSsefSRAhUiHWxTD+NPU2xLNIOJF9GUOTXnA0RkVP6YQUSKvIohnEtgkPCtR1VdM5lbAJgNogFFg5jDv8NXkCP1XoMiDyJbn9y5Mp2BkNUZNmZQ==" Aug 25 17:30:02 spla-repro go-librespot[11854]: time="2026-08-25T17:30:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:30:03 spla-repro go-librespot[11854]: time="2026-08-25T17:30:03+02:00" level=debug msg="completed keyexchange" Aug 25 17:30:03 spla-repro go-librespot[11854]: time="2026-08-25T17:30:03+02:00" level=debug msg="completed challenge" Aug 25 17:30:03 spla-repro volumio[11561]: info: Initializing connection to go-librespot Websocket Aug 25 17:30:03 spla-repro go-librespot[11854]: time="2026-08-25T17:30:03+02:00" level=debug msg="new websocket client" Aug 25 17:30:03 spla-repro volumio[11561]: info: Connection to go-librespot Websocket established Aug 25 17:30:03 spla-repro go-librespot[11854]: time="2026-08-25T17:30:03+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:30:03 spla-repro go-librespot[11854]: time="2026-08-25T17:30:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:30:03 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:30:03 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:30:03 spla-repro volumio[11561]: info: Connection to go-librespot Websocket closed Aug 25 17:30:03 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:30:03 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin bluetooth to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin multiroom to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin metavolumio to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin cd_controller to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 25 17:30:04 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 25 17:30:05 spla-repro volumio[11561]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 25 17:30:05 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 25 17:30:05 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:30:05 spla-repro volumio[11561]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 25 17:30:05 spla-repro volumio[11561]: info: Starting MyVolumio Remote Streaming Endpoints Aug 25 17:30:05 spla-repro volumio[11561]: info: MyVolumio login type: Token Aug 25 17:30:05 spla-repro volumio[11561]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 25 17:30:05 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 25 17:30:06 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 25 17:30:06 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:30:06 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 17:30:06 spla-repro go-librespot[11863]: go-librespot daemon starting... Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="app state loaded" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=info msg="zeroconf server listening on port 46033" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="obtained new client token: AAG/ERNy26gQ9qIp12amm76gvvJU5yzoOpLtOD9sKp8gg0NWcQzQO+uUN1gWzvG4HlwcpfPPxsUtwXM+liJYtBC05Z707KQnuxGtG3BI0/X+KvaPLZAwAprApptxu81Dkgqna7X3hSTDYDzFAe9zbFjWPxc92ks96waxO8piyqRhvTtfUfcg9Apkr84njilzRopkEbOOU2p5Q81BICbgzfl97i2354EvqHTWt97Qc1QMh52Fj4X9jA+wfA==" Aug 25 17:30:06 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 25 17:30:06 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 25 17:30:06 spla-repro volumio[11561]: info: Streaming services startup Aug 25 17:30:06 spla-repro volumio[11561]: info: Starting Streaming Daemon Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 25 17:30:06 spla-repro sudo[11888]: volumio : unable to resolve host spla-repro: System error Aug 25 17:30:06 spla-repro volumio[11561]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 25 17:30:06 spla-repro sudo[11888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 25 17:30:06 spla-repro sudo[11888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 17:30:06 spla-repro sudo[11888]: pam_unix(sudo:session): session closed for user root Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="completed keyexchange" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="completed challenge" Aug 25 17:30:06 spla-repro volumio[11561]: info: Getting Spotify volume Aug 25 17:30:06 spla-repro volumio[11561]: info: Initializing connection to go-librespot Websocket Aug 25 17:30:06 spla-repro volumio[11561]: error: Cannot start Volumio Streaming Daemon Aug 25 17:30:06 spla-repro volumio[11561]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 25 17:30:06 spla-repro volumio[11561]: sudo: unable to resolve host spla-repro: System error Aug 25 17:30:06 spla-repro volumio[11561]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 25 17:30:06 spla-repro go-librespot[11864]: time="2026-08-25T17:30:06+02:00" level=debug msg="new websocket client" Aug 25 17:30:06 spla-repro volumio[11561]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 25 17:30:06 spla-repro volumio[11561]: info: Connection to go-librespot Websocket established Aug 25 17:30:07 spla-repro volumio[11561]: info: CoreCommandRouter::volumioGetState Aug 25 17:30:07 spla-repro volumio[11561]: info: CorePlayQueue::getTrack 0 Aug 25 17:30:07 spla-repro go-librespot[11864]: time="2026-08-25T17:30:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 25 17:30:07 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 17:30:07 spla-repro volumio[11561]: info: Connection to go-librespot Websocket closed Aug 25 17:30:07 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 17:30:07 spla-repro volumio[11561]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:30:07 spla-repro volumio[11561]: Error: socket hang up Aug 25 17:30:07 spla-repro volumio[11561]: at connResetException (node:internal/errors:720:14) Aug 25 17:30:07 spla-repro volumio[11561]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 25 17:30:07 spla-repro volumio[11561]: at Socket.emit (node:events:526:35) Aug 25 17:30:07 spla-repro volumio[11561]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 25 17:30:07 spla-repro volumio[11561]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 25 17:30:07 spla-repro volumio[11561]: code: 'ECONNRESET', Aug 25 17:30:07 spla-repro volumio[11561]: response: undefined Aug 25 17:30:07 spla-repro volumio[11561]: } Aug 25 17:30:07 spla-repro volumio[11561]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:30:07 spla-repro sudo[11908]: volumio : unable to resolve host spla-repro: System error Aug 25 17:30:07 spla-repro sudo[11908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 17:29' Aug 25 17:30:07 spla-repro sudo[11908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"