Aug 29 13:10:00 kueche volumio[1120]: info: Loading plugin "mpd"... Aug 29 13:10:00 kueche kernel: netfs: FS-Cache loaded Aug 29 13:10:00 kueche kernel: Key type cifs.spnego registered Aug 29 13:10:00 kueche kernel: Key type cifs.idmap registered Aug 29 13:10:00 kueche kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Aug 29 13:10:00 kueche kernel: CIFS: Attempting to mount //192.168.1.2/music Aug 29 13:10:01 kueche volumio[1120]: info: Loading plugin "upnp_browser"... Aug 29 13:10:02 kueche sudo[1364]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:03 kueche sudo[1338]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:05 kueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Aug 29 13:10:05 kueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 13:10:05 kueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 13:10:05 kueche upmpdcli[1401]: Could not open config: /tmp/upmpdcli.conf Aug 29 13:10:05 kueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:05 kueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 13:10:06 kueche volumio[1120]: info: Starting UPNP Browser Aug 29 13:10:06 kueche volumio[1120]: info: Loading plugin "alarm-clock"... Aug 29 13:10:06 kueche volumio[1120]: info: Loading plugin "airplay_emulation"... Aug 29 13:10:07 kueche volumio[1120]: info: Starting Shairport Sync Aug 29 13:10:07 kueche volumio[1120]: info: Loading plugin "last_100"... Aug 29 13:10:07 kueche volumio[1120]: info: Loading plugin "webradio"... Aug 29 13:10:07 kueche volumio-remote-updater[674]: [2026-08-29 13:10:07] [connect] Successful connection Aug 29 13:10:07 kueche volumio[1120]: info: Loading plugin "i2s_dacs"... Aug 29 13:10:07 kueche volumio[1120]: info: Loading plugin "volumiodiscovery"... Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** For more information see Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 13:10:07 kueche volumio[1120]: *** WARNING *** For more information see Aug 29 13:10:07 kueche node[1120]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 13:10:07 kueche node[1120]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 13:10:07 kueche node[1120]: *** WARNING *** For more information see Aug 29 13:10:07 kueche node[1120]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 13:10:07 kueche node[1120]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 13:10:07 kueche node[1120]: *** WARNING *** For more information see Aug 29 13:10:07 kueche volumio[1120]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 13:10:07 kueche volumio[1120]: info: Discovery: Started advertising with name: Kueche Aug 29 13:10:07 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 13:10:07 kueche volumio[1120]: info: Loading plugin "spop"... Aug 29 13:10:12 kueche volumio[1120]: info: Loading plugin "autostart"... Aug 29 13:10:13 kueche volumio[1120]: info: Applying required configuration parameters for plugin autostart Aug 29 13:10:13 kueche volumio[1120]: info: AutoStart - onVolumioStart - read config.json Aug 29 13:10:13 kueche volumio[1120]: info: Loading plugin "outputs"... Aug 29 13:10:13 kueche volumio[1120]: info: Loading plugin "albumart"... Aug 29 13:10:13 kueche volumio[1120]: info: Plugin example_plugin is not enabled Aug 29 13:10:13 kueche volumio[1120]: info: Loading plugin "inputs"... Aug 29 13:10:13 kueche volumio[1120]: info: Loading plugin "updater_comm"... Aug 29 13:10:13 kueche volumio[1120]: info: Plugin mpdemulation is not enabled Aug 29 13:10:13 kueche volumio[1120]: info: Loading plugin "rest_api"... Aug 29 13:10:14 kueche volumio[1120]: info: Loading plugin "websocket"... Aug 29 13:10:14 kueche volumio[1120]: info: Starting Socket.io Server version 1.7.4 Aug 29 13:10:14 kueche volumio[1120]: info: Loading i18n strings for locale de Aug 29 13:10:14 kueche volumio[1120]: Updating browse sources language Aug 29 13:10:14 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::initPlayerControls Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 13:10:15 kueche volumio[1120]: Express server listening on port 3000 Aug 29 13:10:15 kueche volumio[1120]: [Metrics] WebUI: 26s 174.72ms Aug 29 13:10:15 kueche volumio[1120]: info: CoreStateMachine::resetVolumioState Aug 29 13:10:15 kueche volumio[1120]: info: CoreStateMachine::getcurrentVolume Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 13:10:15 kueche volumio[1120]: info: CoreStateMachine::pushState Aug 29 13:10:15 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 13:10:15 kueche volumio[1120]: info: CoreCommandRouter::volumioPushState Aug 29 13:10:15 kueche sudo[1432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 13:10:16 kueche sudo[1432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:16 kueche sudo[1432]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:16 kueche sudo[1434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 13:10:16 kueche sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:16 kueche sudo[1434]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:16 kueche volumio[1120]: info: Volumio Network Manager: Network status updated: 2 Aug 29 13:10:16 kueche volumio[1418]: Forking 3 albumart workers Aug 29 13:10:17 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:17 kueche volumio[1120]: info: Reloading queue from file Aug 29 13:10:17 kueche volumio[1120]: info: CoreStateMachine::setRepeat null single undefined Aug 29 13:10:17 kueche volumio[1120]: info: CoreStateMachine::pushState Aug 29 13:10:17 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:17 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 13:10:17 kueche volumio[1120]: info: CoreCommandRouter::volumioPushState Aug 29 13:10:17 kueche volumio[1120]: info: CoreStateMachine::setRandom null Aug 29 13:10:17 kueche volumio[1120]: info: CoreStateMachine::pushState Aug 29 13:10:17 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:17 kueche volumio[1120]: info: CoreCommandRouter::volumioPushState Aug 29 13:10:17 kueche volumio[1120]: info: Setting Device type: Raspberry PI Aug 29 13:10:17 kueche volumio[1120]: info: Completed loading Core Plugins Aug 29 13:10:17 kueche volumio[1120]: info: Preparing to generate the ALSA configuration file Aug 29 13:10:18 kueche volumio[1120]: info: Discovery: adding e87c1261-e91b-4ed2-bf72-ac75a6757639 Aug 29 13:10:18 kueche volumio[1120]: info: Discovery: Found device Kueche Aug 29 13:10:18 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:10:18 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:18 kueche sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 13:10:18 kueche sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:18 kueche volumio[1120]: info: Asound.conf file unchanged, so no further update is needed Aug 29 13:10:18 kueche volumio[1120]: info: Output device has changed, restarting MPD Aug 29 13:10:19 kueche volumio[1120]: info: Output device has changed, restarting Shairport Sync Aug 29 13:10:19 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:19 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:19 kueche sudo[1481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 13:10:19 kueche sudo[1481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:19 kueche sudo[1483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 13:10:19 kueche sudo[1483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:19 kueche sudo[1481]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:19 kueche volumio[1120]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 13:10:19 kueche volumio[1120]: info: ___________ START PLUGINS ___________ Aug 29 13:10:19 kueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 13:10:19 kueche systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 13:10:19 kueche volumio[1120]: info: ControllerMpd::onStart: Initializing MPD Aug 29 13:10:19 kueche volumio[1120]: info: Creating MPD Configuration file Aug 29 13:10:20 kueche sudo[1496]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 13:10:20 kueche sudo[1496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 13:10:20 kueche sudo[1505]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 13:10:20 kueche sudo[1496]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:20 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 13:10:20 kueche sudo[1497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 13:10:20 kueche sudo[1497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:20 kueche volumio[1120]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 13:10:20 kueche volumio[1120]: info: [1788001820480] CoreMusicLibrary::Adding element Medienserver Aug 29 13:10:20 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 13:10:20 kueche volumio[1120]: info: UPNP Browser: Client initialized successfully Aug 29 13:10:20 kueche sudo[1506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 13:10:20 kueche sudo[1506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:20 kueche sudo[1503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 13:10:20 kueche sudo[1503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:20 kueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Aug 29 13:10:21 kueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 13:10:21 kueche sudo[1503]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:21 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:21 kueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 13:10:21 kueche systemd[1]: mpd.service: Deactivated successfully. Aug 29 13:10:21 kueche sudo[1478]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:21 kueche systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 13:10:21 kueche systemd[1]: mpd.socket: Deactivated successfully. Aug 29 13:10:21 kueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 13:10:21 kueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 13:10:21 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:21 kueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 13:10:21 kueche systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 13:10:21 kueche systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:10:21 kueche sudo[1497]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:21 kueche volumio[1120]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 13:10:21 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:21 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:21 kueche sudo[1531]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 13:10:21 kueche sudo[1531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 13:10:21 kueche sudo[1542]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 13:10:21 kueche sudo[1531]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:22 kueche volumio-remote-updater[674]: [2026-08-29 13:10:22] [connect] Successful connection Aug 29 13:10:22 kueche volumio5-onboarding[1534]: time=2026-08-29T13:10:22.419+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 13:10:22 kueche volumio[1120]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 13:10:22 kueche volumio[1120]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 13:10:22 kueche volumio[1120]: info: [1788001822494] CoreMusicLibrary::Adding element Last_100 Aug 29 13:10:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 13:10:22 kueche volumio[1120]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 13:10:22 kueche volumio[1120]: info: [1788001822602] CoreMusicLibrary::Adding element Webradio Aug 29 13:10:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 13:10:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 13:10:22 kueche volumio[1120]: info: Initializing BBC Radios Aug 29 13:10:23 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 13:10:23 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:24 kueche volumio[1120]: info: Creating Spotify config file Aug 29 13:10:24 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:31 kueche volumio[1120]: info: AutoStart - onStart - waiting for system ready state Aug 29 13:10:31 kueche volumio[1120]: info: AutoStart - Polling config: interval=5000ms, maxAttempts=60 Aug 29 13:10:31 kueche volumio[1120]: info: AutoStart - Maximum wait time: 300 seconds Aug 29 13:10:31 kueche volumio[1120]: info: AutoStart - Startup volume disabled Aug 29 13:10:31 kueche volumio[1120]: info: AutoStart - Check #1/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:10:32 kueche volumio[1120]: info: Volumio Calling Home Aug 29 13:10:32 kueche volumio5-onboarding[1534]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:49666->127.0.0.1:3000: i/o timeout Aug 29 13:10:32 kueche systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:32 kueche systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 13:10:32 kueche systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 13:10:32 kueche systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:10:32 kueche systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:10:32 kueche volumio5-onboarding[1578]: time=2026-08-29T13:10:32.884+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 13:10:34 kueche mpd[1543]: 2026-08-29T13:10:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 13:10:34 kueche systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 13:10:34 kueche sudo[1483]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:34 kueche sudo[1506]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:36 kueche volumio[1442]: Starting albumart workers Aug 29 13:10:37 kueche volumio[1120]: info: Discovery: this is already registered, e87c1261-e91b-4ed2-bf72-ac75a6757639 Aug 29 13:10:37 kueche volumio[1120]: info: Discovery: Found device Kueche Aug 29 13:10:37 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:10:37 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:37 kueche volumio-remote-updater[674]: [2026-08-29 13:10:37] [connect] Successful connection Aug 29 13:10:37 kueche volumio[1120]: info: MPD Permissions set Aug 29 13:10:37 kueche volumio[1120]: info: Completed starting Core Plugins Aug 29 13:10:37 kueche volumio[1120]: info: ------------------------------------------- Aug 29 13:10:37 kueche volumio[1120]: info: ----- MyVolumio plugins startup ---- Aug 29 13:10:37 kueche volumio[1120]: info: ------------------------------------------- Aug 29 13:10:37 kueche volumio[1120]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 13:10:37 kueche volumio[1120]: info: MPD Permissions set Aug 29 13:10:37 kueche volumio[1120]: info: Upmpdcli Daemon Started Aug 29 13:10:37 kueche volumio[1120]: info: AutoStart - Check #2/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:10:38 kueche volumio[1120]: info: MPD running with PID1543 Aug 29 13:10:38 kueche volumio[1120]: ,establishing connection Aug 29 13:10:38 kueche volumio[1440]: Starting albumart workers Aug 29 13:10:38 kueche volumio[1120]: info: Volumio called home Aug 29 13:10:38 kueche volumio[1120]: info: Spotify config file written Aug 29 13:10:38 kueche sudo[1596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 13:10:38 kueche sudo[1596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:39 kueche volumio[1441]: Starting albumart workers Aug 29 13:10:39 kueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 13:10:39 kueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 13:10:39 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:39 kueche go-librespot[1598]: go-librespot daemon starting... Aug 29 13:10:39 kueche sudo[1596]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:40 kueche go-librespot[1599]: time="2026-08-29T13:10:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:10:40 kueche go-librespot[1599]: time="2026-08-29T13:10:40+02:00" level=debug msg="app state loaded" Aug 29 13:10:40 kueche go-librespot[1599]: time="2026-08-29T13:10:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=info msg="zeroconf server listening on port 34905" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="obtained new client token: AAFmhoIlO29pL5jwvOtBNwKpJXSVuJcOqnYGEumHTkoJP6mCWC/Q5mRvF/biZPpzpZYxoI6S3o7QCVLBtCDs9VckTFrW0BMzmZza+PVqkV+B7/javLdWzNZY4ViT1hlOjCscZIVwJjjy+CapBxc4JMNxO4+pARAJY8WZlD00lQGhEIkJWuGBlS/XSLFFNiW64W3wKDmXzKbyEOxyX4K/Mdi44fxhoDm/3dH91kNYc2uFyOsoKyEm" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="completed keyexchange" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=debug msg="completed challenge" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:10:41 kueche go-librespot[1599]: time="2026-08-29T13:10:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:10:41 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:41 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:10:42 kueche volumio5-onboarding[1578]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:37672->127.0.0.1:3000: i/o timeout Aug 29 13:10:42 kueche systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:42 kueche systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 13:10:43 kueche systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Aug 29 13:10:43 kueche systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:10:43 kueche systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:10:43 kueche volumio5-onboarding[1622]: time=2026-08-29T13:10:43.476+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 13:10:44 kueche volumio[1120]: error: MPD error: The expression evaluated to a falsy value: Aug 29 13:10:44 kueche volumio[1120]: assert.ok(self.idling) Aug 29 13:10:44 kueche volumio[1120]: error: The expression evaluated to a falsy value: Aug 29 13:10:44 kueche volumio[1120]: assert.ok(self.idling) Aug 29 13:10:44 kueche volumio[1120]: error: MPD error: The expression evaluated to a falsy value: Aug 29 13:10:44 kueche volumio[1120]: assert.ok(self.idling) Aug 29 13:10:44 kueche volumio[1120]: error: The expression evaluated to a falsy value: Aug 29 13:10:44 kueche volumio[1120]: assert.ok(self.idling) Aug 29 13:10:44 kueche volumio[1120]: info: AutoStart - Check #3/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 13:10:44 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:44 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:45 kueche go-librespot[1639]: go-librespot daemon starting... Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="app state loaded" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:10:45 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:10:45 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:10:45 kueche volumio[1120]: info: No need to fix Spotify hosts Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=info msg="zeroconf server listening on port 34247" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="obtained new client token: AAHQW9KKZ5i0Anw1WIBfnGWTY88jtDppQF0icizF+f5mIkU+/+IZGlmN6s5I49MHvw4tLlVf3ESJGFAySC4NYBV4pZLFLWg/bNtMchGOeQPiV4bcUeETykEmqR7azr+fwATOblmPJv5IK6AlIf9cMGkzSDJLZ1jwqwXc78dMVQEz6r7H+TZeXM8ebIDUUKiIKJVzxMuKbEImNOhcVLzL/oOjscXuvTMT373t4zoGhn78GMMcdokJCVA=" Aug 29 13:10:45 kueche go-librespot[1645]: time="2026-08-29T13:10:45+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:10:46 kueche go-librespot[1645]: time="2026-08-29T13:10:46+02:00" level=debug msg="completed keyexchange" Aug 29 13:10:46 kueche go-librespot[1645]: time="2026-08-29T13:10:46+02:00" level=debug msg="completed challenge" Aug 29 13:10:46 kueche go-librespot[1645]: time="2026-08-29T13:10:46+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:10:46 kueche go-librespot[1645]: time="2026-08-29T13:10:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:10:46 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:46 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:10:46 kueche volumio[1120]: error: updateQueue error: null Aug 29 13:10:46 kueche volumio[1120]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 29 13:10:47 kueche volumio[1120]: info: New Spotify access tokenBQBlDnu-s8... Aug 29 13:10:47 kueche volumio[1120]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 13:10:47 kueche volumio[1120]: info: Starting Shairport Sync Aug 29 13:10:47 kueche volumio[1120]: info: Starting Shairport Sync Aug 29 13:10:47 kueche volumio[1120]: info: Starting Shairport Sync Aug 29 13:10:47 kueche volumio[1120]: 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: 2 Aug 29 13:10:47 kueche volumio[1120]: 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: 2 Aug 29 13:10:47 kueche volumio[1120]: info: Received Get System Info Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 13:10:47 kueche volumio[1120]: info: Discovery: Getting this device information Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:10:47 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 13:10:47 kueche sudo[1668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 13:10:47 kueche sudo[1668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:47 kueche volumio5-onboarding[1622]: time=2026-08-29T13:10:47.748+02:00 level=INFO msg="system info for 84bd9c0da00b6191fa461b92d6cd22aa" deviceName=Kueche deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 13:10:47 kueche volumio5-onboarding[1622]: time=2026-08-29T13:10:47.771+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 13:10:47 kueche sudo[1670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 13:10:47 kueche volumio[1120]: info: Received Get System Info Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 13:10:47 kueche sudo[1670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 13:10:47 kueche volumio[1120]: info: Discovery: Getting this device information Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:10:47 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:47 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 13:10:47 kueche sudo[1672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 13:10:47 kueche sudo[1672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:10:47 kueche volumio[1120]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 13:10:47 kueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 13:10:47 kueche systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 13:10:47 kueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:47 kueche systemd[1]: shairport-sync.service: Consumed 1.941s CPU time. Aug 29 13:10:47 kueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:48 kueche sudo[1668]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:48 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:10:48 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:10:48 kueche volumio[1120]: info: Shairport-Sync Started Aug 29 13:10:48 kueche volumio[1120]: Error adding Membership: Error: addMembership EINVAL Aug 29 13:10:48 kueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 13:10:48 kueche systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 13:10:48 kueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:48 kueche volumio[1120]: SPOTIFY: User informations: {"account_id":"otmduy5mBP","country":"DE","display_name":"Ginger","email":"db@bu4.eu","explicit_content":{"filter_enabled":true,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/4mng63p2isftjciul9zindsjr"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/4mng63p2isftjciul9zindsjr","id":"4mng63p2isftjciul9zindsjr","images":[],"product":"premium","type":"user","uri":"spotify:user:4mng63p2isftjciul9zindsjr"} Aug 29 13:10:48 kueche volumio[1120]: info: Spotify Successfully logged in Aug 29 13:10:48 kueche volumio[1120]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 13:10:48 kueche volumio[1120]: info: [1788001848260] CoreMusicLibrary::Adding element Spotify Aug 29 13:10:48 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 13:10:48 kueche volumio[1120]: Cannot find translation for source Spotify Aug 29 13:10:48 kueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:48 kueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 13:10:48 kueche systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 13:10:48 kueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:48 kueche sudo[1672]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:48 kueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 13:10:48 kueche sudo[1670]: pam_unix(sudo:session): session closed for user root Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 13:10:48 kueche volumio[1120]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 13:10:49 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 13:10:49 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:49 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:49 kueche go-librespot[1713]: go-librespot daemon starting... Aug 29 13:10:49 kueche go-librespot[1714]: time="2026-08-29T13:10:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:10:49 kueche go-librespot[1714]: time="2026-08-29T13:10:49+02:00" level=debug msg="app state loaded" Aug 29 13:10:49 kueche go-librespot[1714]: time="2026-08-29T13:10:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=info msg="zeroconf server listening on port 34361" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="obtained new client token: AAGH0iM2KZdIAKUpl79DvnMniXKr+CIgUFE/Oi/DGEUViImrH+xnLvG0MuacwK9Z6/7fkBvLSi15/oSaSHXiFICbJMPTTctTrCiz+RE7BIlF3MHuW5u+9lFsSoEcIVh9vxnBqrvSxbh0qthPEzE7XpLrKGTyot83k4oTQEywToBQArvP/iDZTqApyDFCrXgzRvwlSAHQ3n3pneMoshkBevIIP4qfnIz1Tntx7ZtowyaZwZOhoW2Nyas=" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="completed keyexchange" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=debug msg="completed challenge" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:10:50 kueche go-librespot[1714]: time="2026-08-29T13:10:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:10:50 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:50 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:10:52 kueche volumio-remote-updater[674]: [2026-08-29 13:10:52] [connect] Successful connection Aug 29 13:10:54 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 13:10:54 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:54 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:54 kueche go-librespot[1737]: go-librespot daemon starting... Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=debug msg="app state loaded" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=info msg="zeroconf server listening on port 35831" Aug 29 13:10:54 kueche go-librespot[1738]: time="2026-08-29T13:10:54+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=debug msg="obtained new client token: AAED93aEgTDj6jbA2R3r5/ydzcddK5eW5jh1dyLqzceHuygVSGqQeO1BnkpHjhAGbO6WxDe8gai3WVlFdVU8xPxVkg2tPfR8z+8jRW1iE0G94GrO0kfXmjlPb+OWIS8vzcYoYOLAXl71zP2KaA4A2Cu729zdm9IJPhKIX2rnoYFInyRYKRRUt+DxS+ggq8kZi5FBtgKSCxHM73aECwMUmiz7UOUKE3adL2FF0LBG/vHVpgG2/HAld0c=" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=debug msg="completed keyexchange" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=debug msg="completed challenge" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:10:55 kueche go-librespot[1738]: time="2026-08-29T13:10:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:10:55 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:10:55 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:10:58 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 13:10:58 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:58 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:10:58 kueche go-librespot[1748]: go-librespot daemon starting... Aug 29 13:10:58 kueche go-librespot[1749]: time="2026-08-29T13:10:58+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:10:58 kueche go-librespot[1749]: time="2026-08-29T13:10:58+02:00" level=debug msg="app state loaded" Aug 29 13:10:58 kueche go-librespot[1749]: time="2026-08-29T13:10:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=info msg="zeroconf server listening on port 35727" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="obtained new client token: AAGBc6Aka7YMXyhSQXlo0RFv/xTOkLvIpnYuTglKCiXuzusp3iVs6YoZ/5BsKTCs+ipu86avsiCUo+/joELGsbjd4c1e6fqVkP/5qc8Pi57mXR+RikTtojJuF19vcLnT0D6JqsF5sKwi8Dw4L4lTMI+BpJk6brfQKIiU9BMA6fxLRUn2cfwmfx28+U+Dfgj2BhMKnCP53A4jw5swv4EgYLxomvqEQONfTY/HXz6vz8RlbVjvGxqv/tY=" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="completed keyexchange" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=debug msg="completed challenge" Aug 29 13:10:59 kueche go-librespot[1749]: time="2026-08-29T13:10:59+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:00 kueche go-librespot[1749]: time="2026-08-29T13:11:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:00 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:00 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:02 kueche volumio[1120]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 13:11:02 kueche volumio[1120]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 13:11:02 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:02 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:02 kueche volumio[1120]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 13:11:02 kueche volumio[1120]: info: MyVolumio login type: Token Aug 29 13:11:03 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 13:11:03 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:03 kueche volumio[1120]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 13:11:03 kueche volumio[1120]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 13:11:03 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:03 kueche go-librespot[1773]: go-librespot daemon starting... Aug 29 13:11:03 kueche go-librespot[1774]: time="2026-08-29T13:11:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:03 kueche go-librespot[1774]: time="2026-08-29T13:11:03+02:00" level=debug msg="app state loaded" Aug 29 13:11:03 kueche go-librespot[1774]: time="2026-08-29T13:11:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=info msg="zeroconf server listening on port 46763" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="obtained new client token: AAH8Hhb6qh7FykftDgyEwXbj8aWnV8LyrJ16TxqS/aXTuQ7v5ePXQlmeciWA9bIQ5nO6w+KPksPVfD93FsQflW4vpCcBfxzXUIUvMNam/PibQL1nOV8mgIU9Z6LCXJInG5W2/wV0489wXbdkhTDR5O5K+k6tozc5ZAX3cm/d3Gz6t5Te/YOCfLny6hjlm1L88nERp2VTFwZdDoMHIv7Q9y+QqHJsWJMlv/CapoohE8czz2opwzqc" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=debug msg="completed challenge" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:04 kueche go-librespot[1774]: time="2026-08-29T13:11:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:04 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:04 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:07 kueche volumio-remote-updater[674]: [2026-08-29 13:11:07] [connect] Successful connection Aug 29 13:11:07 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 13:11:07 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:07 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:08 kueche go-librespot[1783]: go-librespot daemon starting... Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="app state loaded" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=info msg="zeroconf server listening on port 35669" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="obtained new client token: AAGT2JpeNOBAdElyztgch3+Q/VM+83m1oYTe6uEIGelMRUbYCxn6aeMjXc3WVv00TouRVrU3OugGWT2zVjuyiQaEb4xAnk2vYa0VTwREkLNGMY5ItyUPbT0Lve0LBfg0z2mx8B1qGxo1QirukQ/4pLak3PcGRbGDTVh7p4aOaDmLIUU05hkUGfUgqIHRJzQHeuNqaNubN0192dejmQ9jblTZWKPGS68qsWbWCc3PP8Nl2CbRG08SYM0=" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=debug msg="completed challenge" Aug 29 13:11:08 kueche go-librespot[1784]: time="2026-08-29T13:11:08+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:09 kueche go-librespot[1784]: time="2026-08-29T13:11:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:09 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:09 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:12 kueche volumio[1120]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 13:11:12 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 13:11:12 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:12 kueche volumio[1120]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 13:11:12 kueche volumio[1120]: info: Streaming services startup Aug 29 13:11:12 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:12 kueche go-librespot[1793]: go-librespot daemon starting... Aug 29 13:11:12 kueche volumio[1120]: info: Starting Streaming Daemon Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=debug msg="app state loaded" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:12 kueche volumio[1120]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 13:11:12 kueche sudo[1803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 13:11:12 kueche sudo[1803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=info msg="zeroconf server listening on port 36529" Aug 29 13:11:12 kueche go-librespot[1794]: time="2026-08-29T13:11:12+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:13 kueche sudo[1803]: pam_unix(sudo:session): session closed for user root Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=debug msg="obtained new client token: AAGHgNc6Na6wJ4Qp3dP6IdDskwTTQPcqvEqBuR9c+TpcDZg5vZP6G4SIAkweve6+Ax+ls6oUi5VUVLn6eXALPp9ndUYH5PvXE2AEg1KXx3/tKpcthOFlo5kkX9cNRHMP/kQoFueJ6E1gBVUgy3j2DvESeIvl6VYInroPOcscjNxIDp5f5nfjulkx7udLcVKoI1He72wo1tf2i2Uw5RMBqBDVqoXFEh7Ll8Ta1MiXnjh757fiS4kf" Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=debug msg="completed challenge" Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:13 kueche go-librespot[1794]: time="2026-08-29T13:11:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:13 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:13 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:13 kueche volumio[1120]: info: Shairport-Sync Started Aug 29 13:11:13 kueche volumio[1120]: info: AutoStart - Check #4/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:11:13 kueche volumio[1120]: info: go-librespot daemon successfully initialized Aug 29 13:11:13 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 13:11:13 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:13 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 13:11:14 kueche volumio[1120]: error: Cannot start Volumio Streaming Daemon Aug 29 13:11:14 kueche volumio[1120]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 13:11:14 kueche volumio[1120]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 13:11:14 kueche volumio[1120]: info: Shairport-Sync Started Aug 29 13:11:14 kueche volumio[1120]: error: An error occurred while listing Spotify featured playlists Error: Client network socket disconnected before secure TLS connection was established Aug 29 13:11:14 kueche volumio[1120]: info: An error occurred while getting Spotify ROOT Discover Folders: Aug 29 13:11:14 kueche volumio[1120]: error: An error occurred while listing Spotify new albums Error: Client network socket disconnected before secure TLS connection was established Aug 29 13:11:14 kueche volumio[1120]: error: An error occurred while listing Spotify categories Error: Client network socket disconnected before secure TLS connection was established Aug 29 13:11:16 kueche volumio[1120]: error: MyVolumio Custom Token format not valid, refreshing it Aug 29 13:11:16 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 13:11:16 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:16 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:16 kueche go-librespot[1828]: go-librespot daemon starting... Aug 29 13:11:16 kueche volumio[1120]: info: Initializing connection to go-librespot Websocket Aug 29 13:11:16 kueche go-librespot[1829]: time="2026-08-29T13:11:16+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:16 kueche go-librespot[1829]: time="2026-08-29T13:11:16+02:00" level=debug msg="app state loaded" Aug 29 13:11:16 kueche go-librespot[1829]: time="2026-08-29T13:11:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=info msg="zeroconf server listening on port 37105" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="obtained new client token: AAGAI5Fl8hvfABnFlsE7C+bVUydFkPpug/7GBl0mGIY/pgS7Ve4GO8kVrlFxNFGML71WJ8FwdYvJWskQZiPmLqiBxIzXR7ZGqubq1e4Y9FkTnObrlJj+hdKwItPJAJvmMFFhZ8Jyg3DksLwOcx7hxx1LH+YTP81QlHmQyySl28TsWqccoNApYI0Ll5VQPZUpQ8FEJWfQ+87B5STtSh5ZWbZNcZmMw17IDYZvmuD1Yq/X1psgGSRL9zA=" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=debug msg="completed challenge" Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:17 kueche volumio5-onboarding[1622]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Aug 29 13:11:17 kueche systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:17 kueche systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 13:11:17 kueche systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Aug 29 13:11:17 kueche systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:11:17 kueche go-librespot[1829]: time="2026-08-29T13:11:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:17 kueche systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 13:11:17 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:17 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 29 13:11:18 kueche volumio5-onboarding[1838]: time=2026-08-29T13:11:18.078+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 13:11:18 kueche volumio[1120]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 13:11:18 kueche volumio[1120]: 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: 2 Aug 29 13:11:18 kueche volumio[1120]: info: AutoStart - Check #5/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:11:18 kueche volumio[1120]: 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: 2 Aug 29 13:11:18 kueche volumio[1120]: info: Received Get System Info Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 13:11:18 kueche volumio[1120]: info: Discovery: Getting this device information Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:11:18 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:11:18 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 13:11:19 kueche volumio5-onboarding[1838]: time=2026-08-29T13:11:19.026+02:00 level=INFO msg="system info for 84bd9c0da00b6191fa461b92d6cd22aa" deviceName=Kueche deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 13:11:19 kueche volumio5-onboarding[1838]: time=2026-08-29T13:11:19.073+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 13:11:19 kueche volumio[1120]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 29 13:11:19 kueche volumio[1120]: info: Received Get System Info Aug 29 13:11:19 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 13:11:19 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 13:11:19 kueche volumio[1120]: info: Discovery: Getting this device information Aug 29 13:11:19 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:11:19 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:11:19 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 13:11:20 kueche volumio[1120]: info: MyVolumio login type: Token Aug 29 13:11:20 kueche volumio[1120]: info: CoreCommandRouter::volumioGetState Aug 29 13:11:20 kueche volumio[1120]: info: CorePlayQueue::getTrack 0 Aug 29 13:11:21 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 29 13:11:21 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:21 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:21 kueche go-librespot[1847]: go-librespot daemon starting... Aug 29 13:11:21 kueche go-librespot[1848]: time="2026-08-29T13:11:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:21 kueche go-librespot[1848]: time="2026-08-29T13:11:21+02:00" level=debug msg="app state loaded" Aug 29 13:11:21 kueche go-librespot[1848]: time="2026-08-29T13:11:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:22 kueche volumio[1120]: info: Initializing connection to go-librespot Websocket Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="new websocket client" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=info msg="zeroconf server listening on port 40673" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:22 kueche volumio[1120]: info: Connection to go-librespot Websocket established Aug 29 13:11:22 kueche volumio-remote-updater[674]: [2026-08-29 13:11:22] [connect] Successful connection Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="obtained new client token: AAHlD7BYVevNMAQ33c8hcnpRQHVsHRGxEOCK5lxvp27VzhvFdJKxT+g4Im3drKeJiABDxLoXHvy+qQwa1380xOjtEBD0bfYv3ZYxE0UUGbMtcpfgK2csa4opKgIQOg2cNXJtodfx1LQ4n+/reBOh3/gFujxAJ3IyRBjfEwObnOnw4Xxz80sOtmQFnWCSn4MtcGU8yLuSSUoZXog8fxfSpncFUq83QWsGKyr1yrWpfsY6GzQTAWHl" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=debug msg="completed challenge" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11:22+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:22 kueche go-librespot[1848]: time="2026-08-29T13:11: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 29 13:11:22 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:22 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 13:11:22 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 13:11:22 kueche volumio[1120]: info: Connection to go-librespot Websocket closed Aug 29 13:11:23 kueche volumio[1120]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 13:11:23 kueche volumio-remote-updater[674]: [2026-08-29 13:11:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788001882 101 Aug 29 13:11:23 kueche volumio[1120]: 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 29 13:11:24 kueche volumio[1120]: info: AutoStart - Check #6/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 13:11:24 kueche volumio[1120]: info: MyVolumio token set successfully Aug 29 13:11:24 kueche volumio[1120]: info: MYVOLUMIO: Adding device Aug 29 13:11:24 kueche volumio[1120]: info: MYVOLUMIO: Evaluating Server Aug 29 13:11:25 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 29 13:11:25 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:25 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:25 kueche go-librespot[1891]: go-librespot daemon starting... Aug 29 13:11:25 kueche go-librespot[1892]: time="2026-08-29T13:11:25+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:25 kueche go-librespot[1892]: time="2026-08-29T13:11:25+02:00" level=debug msg="app state loaded" Aug 29 13:11:25 kueche go-librespot[1892]: time="2026-08-29T13:11:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:25 kueche volumio[1120]: info: Getting Spotify volume Aug 29 13:11:26 kueche volumio[1120]: info: MyVolumio status changed Aug 29 13:11:26 kueche volumio[1120]: info: Streaming services startup Aug 29 13:11:26 kueche volumio[1120]: info: Starting Streaming Daemon Aug 29 13:11:26 kueche volumio[1120]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 13:11:26 kueche volumio[1120]: info: Removing audio output: Aug 29 13:11:26 kueche volumio[1120]: info: Stoppping Tunnel 1 Aug 29 13:11:26 kueche sudo[1902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 13:11:26 kueche sudo[1902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=info msg="zeroconf server listening on port 42461" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:26 kueche sudo[1905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 13:11:26 kueche sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="obtained new client token: AAE3s1gLp7T8xuUym3oVhwntG4py+hqo4sD468n7YtL/ffQOjVbdBnEnlPDraBxCpk3o3b7JiFq8ZHFr3aBXtQqx7B5QgjatSU7c128jeeEVMFh2tXlIW6sXC7544GFITnrNej9G73PUsMT+uFXC8lnIQ4jJeN/Zm9Sqjji76bIoKcTVbNBhiIN8SSrtRq+Q8CR/Kv2BgiJnSQk5Sr7hxoHhV8+I9J5UD5+BrQb0T6+G7FAdXfnNoS4=" Aug 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche 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 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:26 kueche sudo[1905]: pam_unix(sudo:session): session closed for user root Aug 29 13:11:26 kueche sudo[1902]: pam_unix(sudo:session): session closed for user root Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=debug msg="completed challenge" Aug 29 13:11:26 kueche go-librespot[1892]: time="2026-08-29T13:11:26+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:26 kueche volumio[1120]: info: Setting Geolocation for MyVolumio to eu6 Aug 29 13:11:27 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:27 kueche go-librespot[1892]: time="2026-08-29T13:11:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:27 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:27 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:27 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:27 kueche volumio[1120]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 13:11:27 kueche volumio[1120]: info: Initializing connection to go-librespot Websocket Aug 29 13:11:27 kueche volumio[1120]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 13:11:27 kueche volumio[1120]: Error: socket hang up Aug 29 13:11:27 kueche volumio[1120]: at connResetException (node:internal/errors:720:14) Aug 29 13:11:27 kueche volumio[1120]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 29 13:11:27 kueche volumio[1120]: at Socket.emit (node:events:526:35) Aug 29 13:11:27 kueche volumio[1120]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 29 13:11:27 kueche volumio[1120]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 29 13:11:27 kueche volumio[1120]: code: 'ECONNRESET', Aug 29 13:11:27 kueche volumio[1120]: response: undefined Aug 29 13:11:27 kueche volumio[1120]: } Aug 29 13:11:27 kueche volumio[1120]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 13:11:30 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 29 13:11:30 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:30 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:30 kueche go-librespot[1919]: go-librespot daemon starting... Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=debug msg="app state loaded" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=info msg="zeroconf server listening on port 46367" Aug 29 13:11:30 kueche go-librespot[1920]: time="2026-08-29T13:11:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=debug msg="obtained new client token: AAHg7z38wyPBx7EWeANLPm34gravEKmSM70dPw0orhGK2suwWfqtVa5gArSfAEjeFs9PTgWJM2xLZXCNApH2O4T7wHyrBHKTC29jQaLkUnXa+XzYcEFtDIzZvSC+aWK7U+tDR/KOqatzAf/j6BCUb6MCeRYkxsRyb40BNWQyaiRvsIBsYZeoeY76xOUsspPdzUHH5u5cvj2dwwvpo37V1UI8msFmN/Sm2WuIiyUH1G9Q9LS0Us94" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=debug msg="completed challenge" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:31 kueche go-librespot[1920]: time="2026-08-29T13:11:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:31 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:31 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 13:11:34 kueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 29 13:11:34 kueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:34 kueche go-librespot[1943]: go-librespot daemon starting... Aug 29 13:11:34 kueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 13:11:34 kueche go-librespot[1944]: time="2026-08-29T13:11:34+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 13:11:34 kueche go-librespot[1944]: time="2026-08-29T13:11:34+02:00" level=debug msg="app state loaded" Aug 29 13:11:34 kueche go-librespot[1944]: time="2026-08-29T13:11:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=info msg="zeroconf server listening on port 34837" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="obtained new client token: AAG1eTQcSqODh/SmuYbnasyySGyUOvP5/AqfNrzuPYULZkzUEt7kMCnFZzE7Brbq5/DI6NEnDbZTn3OEJvxqcc8FIh67oWTRj9UIdAbs9Ihqg3JwyYva/iS19ydy1xnz7YU80fZTS3GETBwuLFTk3G/lSewZOZVrZ1/V+VwkK4z1VY9rnmJLO+LHo45aKpPCqBxAHwAW7zkGtLjf26AXsFAmquv5Rknd/RNb3rCIf2HmMEkfwu5KUY4=" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="completed keyexchange" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=debug msg="completed challenge" Aug 29 13:11:35 kueche go-librespot[1944]: time="2026-08-29T13:11:35+02:00" level=info msg="authenticated AP" username="4m*********************jr" Aug 29 13:11:35 kueche sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 13:10' Aug 29 13:11:35 kueche sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 13:11:36 kueche go-librespot[1944]: time="2026-08-29T13:11:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 13:11:36 kueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 13:11:36 kueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"