Aug 26 14:19:00 volumio4 volumio[1249]: info: Volumio Network Manager: Network status updated: 2 Aug 26 14:19:01 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 26 14:19:01 volumio4 volumio[1249]: info: Reloading queue from file Aug 26 14:19:02 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 26 14:19:02 volumio4 volumio[1249]: info: Setting Device type: Raspberry PI Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreStateMachine::setRepeat null single undefined Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreStateMachine::pushState Aug 26 14:19:02 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreCommandRouter::volumioPushState Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreStateMachine::setRandom null Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreStateMachine::pushState Aug 26 14:19:02 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:02 volumio4 volumio[1249]: info: CoreCommandRouter::volumioPushState Aug 26 14:19:02 volumio4 volumio[1518]: Starting albumart workers Aug 26 14:19:02 volumio4 volumio[1249]: info: Completed loading Core Plugins Aug 26 14:19:02 volumio4 volumio[1249]: info: Preparing to generate the ALSA configuration file Aug 26 14:19:02 volumio4 volumio[1517]: Starting albumart workers Aug 26 14:19:02 volumio4 volumio[1249]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 26 14:19:02 volumio4 volumio[1249]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Aug 26 14:19:02 volumio4 volumio[1249]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 26 14:19:03 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 26 14:19:03 volumio4 sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 26 14:19:03 volumio4 sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:03 volumio4 volumio[1249]: info: Discovery: adding c21b4483-4d3b-414c-92ca-1bc634784037 Aug 26 14:19:03 volumio4 volumio[1249]: info: Discovery: Found device Volumio4 Aug 26 14:19:03 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:03 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:03 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 26 14:19:03 volumio4 volumio[1249]: info: Discovery: this is already registered, c21b4483-4d3b-414c-92ca-1bc634784037 Aug 26 14:19:03 volumio4 volumio[1249]: info: Discovery: Found device Volumio4 Aug 26 14:19:03 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:03 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:04 volumio4 volumio[1249]: info: Asound.conf file unchanged, so no further update is needed Aug 26 14:19:04 volumio4 volumio[1249]: info: Output device has changed, restarting MPD Aug 26 14:19:04 volumio4 volumio[1249]: info: Output device has changed, restarting Shairport Sync Aug 26 14:19:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:04 volumio4 sudo[1587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 14:19:04 volumio4 sudo[1587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:04 volumio4 sudo[1587]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:04 volumio4 sudo[1589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 14:19:04 volumio4 sudo[1589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:04 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 14:19:04 volumio4 volumio[1249]: info: ___________ START PLUGINS ___________ Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Starting plugin Aug 26 14:19:05 volumio4 volumio[1516]: Starting albumart workers Aug 26 14:19:05 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 14:19:05 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 14:19:05 volumio4 sudo[1597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 14:19:05 volumio4 sudo[1597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Loaded bundled presets v1.5.5 Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Active presets source: bundled, 224 presets loaded Aug 26 14:19:05 volumio4 sudo[1599]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Detected model: Raspberry Pi 4 Model B Rev 1.4 Aug 26 14:19:05 volumio4 sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 14:19:05 volumio4 sudo[1601]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 26 14:19:05 volumio4 sudo[1599]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:05 volumio4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Aug 26 14:19:05 volumio4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Detected SoC: bcm2711 Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Detected RAM: 3783 MB Aug 26 14:19:05 volumio4 volumio[1249]: info: pi_screen_setup: Hardware detection complete - {"model":"Pi 4","model_raw":"Raspberry Pi 4 Model B Rev 1.4","soc":"bcm2711","ram_mb":3783,"hdmi_ports":2,"dsi_ports":["dsi0","dsi1"],"has_composite":true,"kms_supported":true,"kms_overlay":"vc4-kms-v3d-pi4","is_pi":true} Aug 26 14:19:05 volumio4 volumio[1249]: info: ControllerMpd::onStart: Initializing MPD Aug 26 14:19:05 volumio4 volumio[1249]: info: Creating MPD Configuration file Aug 26 14:19:05 volumio4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 14:19:05 volumio4 sudo[1582]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:05 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:19:05 volumio4 sudo[1597]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:05 volumio4 sudo[1618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 14:19:05 volumio4 sudo[1618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:05 volumio4 sudo[1618]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:06 volumio4 sudo[1606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 14:19:06 volumio4 sudo[1606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 14:19:06 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 14:19:06 volumio4 systemd[1]: mpd.service: Deactivated successfully. Aug 26 14:19:06 volumio4 volumio[1249]: info: [1787746746176] CoreMusicLibrary::Adding element Media Servers Aug 26 14:19:06 volumio4 systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 14:19:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 14:19:06 volumio4 systemd[1]: mpd.socket: Deactivated successfully. Aug 26 14:19:06 volumio4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 14:19:06 volumio4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 14:19:06 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 14:19:06 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 14:19:06 volumio4 volumio-remote-updater[729]: [2026-08-26 14:19:06] [connect] Successful connection Aug 26 14:19:06 volumio4 volumio[1249]: info: UPNP Browser: Client initialized successfully Aug 26 14:19:06 volumio4 volumio5-onboarding[1607]: time=2026-08-26T14:19:06.684+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:19:06 volumio4 sudo[1627]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 14:19:06 volumio4 sudo[1627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 14:19:06 volumio4 sudo[1644]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 26 14:19:06 volumio4 sudo[1627]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:07 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:07 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 14:19:07 volumio4 volumio[1249]: info: [1787746747782] CoreMusicLibrary::Adding element Last_100 Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 14:19:07 volumio4 volumio[1249]: info: [1787746747852] CoreMusicLibrary::Adding element Webradio Aug 26 14:19:07 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 14:19:08 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 14:19:08 volumio4 volumio[1249]: info: Initializing BBC Radios Aug 26 14:19:08 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 14:19:08 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:08 volumio4 volumio[1249]: info: Creating Spotify config file Aug 26 14:19:08 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:09 volumio4 volumio[1249]: info: [now-playing] ConfigUpdater: config is up to date. Aug 26 14:19:09 volumio4 volumio[1249]: info: Loading i18n strings for locale nl Aug 26 14:19:09 volumio4 volumio[1249]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Aug 26 14:19:09 volumio4 volumio[1249]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 26 14:19:09 volumio4 volumio[1249]: info: Loading i18n strings for locale nl Aug 26 14:19:10 volumio4 volumio[1249]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Aug 26 14:19:10 volumio4 volumio[1249]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 26 14:19:10 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 14:19:10 volumio4 sudo[1672]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 26 14:19:10 volumio4 sudo[1672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:10 volumio4 volumio[1249]: info: Volumio Calling Home Aug 26 14:19:10 volumio4 sudo[1672]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:11 volumio4 volumio[1249]: info: pi_screen_setup: Management server started on port 4567 Aug 26 14:19:11 volumio4 sudo[1691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 26 14:19:11 volumio4 sudo[1691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:11 volumio4 sudo[1689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 26 14:19:11 volumio4 sudo[1693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 26 14:19:11 volumio4 sudo[1693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:11 volumio4 sudo[1689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:12 volumio4 systemd[1]: Reloading. Aug 26 14:19:14 volumio4 sudo[1691]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:14 volumio4 systemd[1]: Reloading. Aug 26 14:19:15 volumio4 volumio[1249]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): OpenWeatherMap API-sleutel niet geconfigureerd. Voeg deze toe in de weerservice-instellingen. Aug 26 14:19:15 volumio4 volumio[1249]: info: [now-playing] App is listening on port 4004. Aug 26 14:19:15 volumio4 mpd[1645]: 2026-08-26T14:19:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 14:19:15 volumio4 volumio[1249]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Aug 26 14:19:15 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: adding 707e09cf-e7b3-4a2d-a82d-23c0db20a9c1 Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: Found device Volumio-Woonkamer Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: Connecting to remote: 192.168.1.80 Aug 26 14:19:16 volumio4 volumio[1249]: info: touch_display: No backlight interface detected. Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: adding 7ebb1fba-d4cc-40ff-ae8b-e2a891b38568 Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: Found device Volumio-lcd Aug 26 14:19:16 volumio4 volumio[1249]: info: Discovery: Connecting to remote: 192.168.1.242 Aug 26 14:19:16 volumio4 volumio5-onboarding[1607]: 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:51954->127.0.0.1:3000: i/o timeout Aug 26 14:19:17 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 26 14:19:17 volumio4 volumio[1249]: info: touch_display: systemctl disable getty@tty1.service succeeded. Aug 26 14:19:17 volumio4 volumio[1249]: info: minidlna: Found miniDLNA version 1.3.0 Aug 26 14:19:17 volumio4 volumio[1249]: info: minidlna: Starting minidlna.service Aug 26 14:19:17 volumio4 volumio[1249]: info: MPD Permissions set Aug 26 14:19:17 volumio4 volumio[1249]: info: MPD Permissions set Aug 26 14:19:17 volumio4 volumio[1249]: info: Upmpdcli Daemon Started Aug 26 14:19:17 volumio4 volumio[1249]: 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 26 14:19:17 volumio4 volumio[1249]: info: Volumio called home Aug 26 14:19:17 volumio4 systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 14:19:17 volumio4 sudo[1693]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:17 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:17 volumio4 sudo[1606]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:17 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 14:19:17 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 26 14:19:17 volumio4 sudo[1689]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:17 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:19:17 volumio4 sudo[1589]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:17 volumio4 sudo[1759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Aug 26 14:19:17 volumio4 sudo[1759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:17 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:19:17 volumio4 volumio5-onboarding[1761]: time=2026-08-26T14:19:17.782+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:19:17 volumio4 sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Aug 26 14:19:17 volumio4 sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:18 volumio4 systemd[1]: Started minidlna.service - MiniDLNA lightweight DLNA/UPnP-AV server. Aug 26 14:19:18 volumio4 sudo[1759]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:18 volumio4 sudo[1757]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:18 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 26 14:19:18 volumio4 volumio[1249]: info: Discovery: Connected to remote: 192.168.1.242 Aug 26 14:19:18 volumio4 volumio[1249]: info: Spotify config file written Aug 26 14:19:19 volumio4 sudo[1777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 14:19:19 volumio4 sudo[1777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:19 volumio4 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 26 14:19:19 volumio4 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 26 14:19:19 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:19 volumio4 go-librespot[1779]: go-librespot daemon starting... Aug 26 14:19:19 volumio4 sudo[1777]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+02:00" level=debug msg="app state loaded" Aug 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+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 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+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 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+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 26 14:19:20 volumio4 go-librespot[1780]: time="2026-08-26T14:19:20+02:00" level=info msg="zeroconf server listening on port 39273" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="obtained new client token: AAHuVXxQeJhwlhbgzKPPHEoiwvZt/cE1DACeRskBy1mxGle/w4Ia52KoR4j6X6dH2bQUguEaVA+SMIVw0or3CRMDdI/Eo8/zKt02JK12CAiu0pLXtJm2clFIKaDocpdjwBMSGvflQPuONmokUUGftepYYaMx3KnqPhf5x6dg0qq7v6KMsGeOms2bYAI9zoZEaCnGdwcuf07lwaS9CmQwN7FTWMtRRS4u8sJxkAlD3hzb6oiUNBdYsj4t" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="completed challenge" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:21 volumio4 volumio-remote-updater[729]: [2026-08-26 14:19:21] [connect] Successful connection Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=debug msg="completed challenge" Aug 26 14:19:21 volumio4 go-librespot[1780]: time="2026-08-26T14:19:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:22 volumio4 go-librespot[1780]: time="2026-08-26T14:19:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:19:22 volumio4 go-librespot[1780]: time="2026-08-26T14:19:22+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:22 volumio4 go-librespot[1780]: time="2026-08-26T14:19:22+02:00" level=debug msg="completed challenge" Aug 26 14:19:22 volumio4 go-librespot[1780]: time="2026-08-26T14:19:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:23 volumio4 go-librespot[1780]: time="2026-08-26T14:19:23+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 14:19:23 volumio4 go-librespot[1780]: time="2026-08-26T14:19:23+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 14:19:23 volumio4 go-librespot[1780]: time="2026-08-26T14:19:23+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:23 volumio4 go-librespot[1780]: time="2026-08-26T14:19:23+02:00" level=debug msg="completed challenge" Aug 26 14:19:23 volumio4 go-librespot[1780]: time="2026-08-26T14:19:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:23 volumio4 volumio[1249]: info: Discovery: Connected to remote: 192.168.1.80 Aug 26 14:19:23 volumio4 volumio[1249]: info: minidlna: systemctl start minidlna.service succeeded. Aug 26 14:19:23 volumio4 volumio[1249]: info: touch_display: systemctl stop getty@tty1.service succeeded. Aug 26 14:19:23 volumio4 volumio[1249]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 26 14:19:23 volumio4 volumio[1249]: info: touch_display: systemctl daemon-reload succeeded. Aug 26 14:19:24 volumio4 volumio[1249]: info: No need to fix Spotify hosts Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 go-librespot[1780]: time="2026-08-26T14:19:24+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 go-librespot[1780]: time="2026-08-26T14:19:24+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:24 volumio4 go-librespot[1780]: time="2026-08-26T14:19:24+02:00" level=debug msg="completed challenge" Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:24 volumio4 sudo[1792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 sudo[1792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:24 volumio4 go-librespot[1780]: time="2026-08-26T14:19:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:24 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:19:24 volumio4 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Aug 26 14:19:25 volumio4 sudo[1792]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+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 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+02:00" level=debug msg="completed challenge" Aug 26 14:19:25 volumio4 startx[1827]: X.Org X Server 1.21.1.7 Aug 26 14:19:25 volumio4 startx[1827]: X Protocol Version 11, Revision 0 Aug 26 14:19:25 volumio4 startx[1827]: Current Operating System: Linux volumio4 6.12.47-v7l+ #1904 SMP Mon Sep 15 13:08:10 BST 2025 armv7l Aug 26 14:19:25 volumio4 startx[1827]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 snd_bcm2835.enable_hdmi=0 video=HDMI-A-1:640x480M@60D numa=fake=2 system_heap.max_order=0 smsc95xx.macaddr=E4:5F:01:29:09:49 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=7e9efb31-d81e-40e6-b369-17d6be2a2543 imgfile=/volumio_current.sqsh bootpart=UUID=41F4-3F60 datapart=UUID=d86abd49-9ab6-4e7d-8df3-6405c27b7066 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Aug 26 14:19:25 volumio4 startx[1827]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Aug 26 14:19:25 volumio4 startx[1827]: Current version of pixman: 0.44.0 Aug 26 14:19:25 volumio4 startx[1827]: Before reporting problems, check http://wiki.x.org Aug 26 14:19:25 volumio4 startx[1827]: to make sure that you have the latest version. Aug 26 14:19:25 volumio4 startx[1827]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 26 14:19:25 volumio4 startx[1827]: (++) from command line, (!!) notice, (II) informational, Aug 26 14:19:25 volumio4 startx[1827]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 26 14:19:25 volumio4 startx[1827]: (==) Log file: "/var/log/Xorg.0.log", Time: Wed Aug 26 14:19:25 2026 Aug 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:25 volumio4 go-librespot[1780]: time="2026-08-26T14:19:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:25 volumio4 startx[1827]: (==) Using config directory: "/etc/X11/xorg.conf.d" Aug 26 14:19:25 volumio4 startx[1827]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 26 14:19:25 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:25 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:19:27 volumio4 volumio[1249]: error: MPD error: The expression evaluated to a falsy value: Aug 26 14:19:27 volumio4 volumio[1249]: assert.ok(self.idling) Aug 26 14:19:27 volumio4 volumio[1249]: error: The expression evaluated to a falsy value: Aug 26 14:19:27 volumio4 volumio[1249]: assert.ok(self.idling) Aug 26 14:19:27 volumio4 volumio5-onboarding[1761]: 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:57486->127.0.0.1:3000: i/o timeout Aug 26 14:19:27 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:27 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 14:19:27 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Aug 26 14:19:27 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:19:27 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:19:28 volumio4 volumio5-onboarding[1850]: time=2026-08-26T14:19:28.088+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:19:28 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 26 14:19:28 volumio4 volumio[1249]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Aug 26 14:19:28 volumio4 volumio[1249]: info: touch_display: Volumio Kiosk started. Aug 26 14:19:28 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:28 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:28 volumio4 volumio[1249]: info: Completed starting Core Plugins Aug 26 14:19:28 volumio4 volumio[1249]: info: ------------------------------------------- Aug 26 14:19:28 volumio4 volumio[1249]: info: ----- MyVolumio plugins startup ---- Aug 26 14:19:28 volumio4 volumio[1249]: info: ------------------------------------------- Aug 26 14:19:28 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 14:19:28 volumio4 volumio[1249]: info: MPD running with PID1645 Aug 26 14:19:28 volumio4 volumio[1249]: ,establishing connection Aug 26 14:19:28 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 14:19:28 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:28 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:28 volumio4 go-librespot[1879]: go-librespot daemon starting... Aug 26 14:19:28 volumio4 go-librespot[1880]: time="2026-08-26T14:19:28+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:19:28 volumio4 go-librespot[1880]: time="2026-08-26T14:19:28+02:00" level=debug msg="app state loaded" Aug 26 14:19:28 volumio4 go-librespot[1880]: time="2026-08-26T14:19:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:19:28 volumio4 volumio[1249]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Aug 26 14:19:28 volumio4 sudo[1889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 26 14:19:29 volumio4 sudo[1889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:29 volumio4 sudo[1889]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:29 volumio4 volumio[1249]: error: updateQueue error: null Aug 26 14:19:29 volumio4 volumio[1249]: info: New Spotify access tokenBQAuXFOb29... Aug 26 14:19:29 volumio4 volumio[1249]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+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 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+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 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+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 26 14:19:29 volumio4 sudo[1904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Aug 26 14:19:29 volumio4 sudo[1904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+02:00" level=info msg="zeroconf server listening on port 37437" Aug 26 14:19:29 volumio4 sudo[1904]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+02:00" level=debug msg="obtained new client token: AAG6m7vkteD7ZDAJq5OrnTiq003xxuxgv0RgWPW12Dqel5Tokhq5JEi6uN6a874JGf0an974dN0bL5YGo1J6VmPeZdGjceKeDVB+k55IDqMlX0gcDU2h38HyLMHdpzm+teTdY+OhG097c33qaAeUsuNhoLawe+DVcuzchgvBfofy8ywpeOfZqaHTLwKH1P+zl1b9qEzEIy3zVnGmjhUToBSbBDLS5BrPgi4EEMh5XkSr0h0Ab/sNdQL0" Aug 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:29 volumio4 go-librespot[1880]: time="2026-08-26T14:19:29+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.166:48240->34.158.1.133:4070: read: connection reset by peer" Aug 26 14:19:29 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 26 14:19:30 volumio4 volumio[1249]: info: go-librespot daemon successfully initialized Aug 26 14:19:30 volumio4 volumio[1249]: info: Starting Shairport Sync Aug 26 14:19:30 volumio4 go-librespot[1880]: time="2026-08-26T14:19:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:30 volumio4 volumio[1249]: info: Starting Shairport Sync Aug 26 14:19:30 volumio4 go-librespot[1880]: time="2026-08-26T14:19:30+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:30 volumio4 volumio[1249]: info: Starting Shairport Sync Aug 26 14:19:30 volumio4 go-librespot[1880]: time="2026-08-26T14:19:30+02:00" level=debug msg="completed challenge" Aug 26 14:19:30 volumio4 sudo[1942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 14:19:30 volumio4 go-librespot[1880]: time="2026-08-26T14:19:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:30 volumio4 sudo[1942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:30 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Aug 26 14:19:30 volumio4 sudo[1945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 14:19:30 volumio4 sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:30 volumio4 volumio[1249]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Aug 26 14:19:30 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 14:19:30 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 14:19:30 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 14:19:30 volumio4 systemd[1]: shairport-sync.service: Consumed 1.780s CPU time. Aug 26 14:19:30 volumio4 sudo[1946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 14:19:30 volumio4 sudo[1946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:19:30 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 14:19:30 volumio4 sudo[1945]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:30 volumio4 sudo[1942]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:30 volumio4 go-librespot[1880]: time="2026-08-26T14:19:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:19:31 volumio4 go-librespot[1880]: time="2026-08-26T14:19:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:19:31 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 14:19:31 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 14:19:31 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 14:19:31 volumio4 volumio[1249]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 26 14:19:31 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 14:19:31 volumio4 volumio[1249]: info: touch_display: X display number found: 0 Aug 26 14:19:31 volumio4 sudo[1946]: pam_unix(sudo:session): session closed for user root Aug 26 14:19:31 volumio4 volumio[1249]: error: updateQueue error: null Aug 26 14:19:31 volumio4 go-librespot[1880]: time="2026-08-26T14:19:31+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 26 14:19:31 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Aug 26 14:19:31 volumio4 volumio[1249]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 26 14:19:31 volumio4 go-librespot[1880]: time="2026-08-26T14:19:31+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:31 volumio4 go-librespot[1880]: time="2026-08-26T14:19:31+02:00" level=debug msg="completed challenge" Aug 26 14:19:31 volumio4 volumio[1249]: info: Shairport-Sync Started Aug 26 14:19:31 volumio4 go-librespot[1880]: time="2026-08-26T14:19:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:32 volumio4 volumio[1249]: Error adding Membership: Error: addMembership EINVAL Aug 26 14:19:32 volumio4 volumio[1249]: info: Shairport-Sync Started Aug 26 14:19:32 volumio4 volumio[1249]: info: Shairport-Sync Started Aug 26 14:19:32 volumio4 go-librespot[1880]: time="2026-08-26T14:19:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 14:19:32 volumio4 go-librespot[1880]: time="2026-08-26T14:19:32+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:32 volumio4 go-librespot[1880]: time="2026-08-26T14:19:32+02:00" level=debug msg="completed challenge" Aug 26 14:19:32 volumio4 go-librespot[1880]: time="2026-08-26T14:19:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:32 volumio4 volumio[1249]: info: touch_display: X display number found: 0 Aug 26 14:19:33 volumio4 volumio[1249]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 14:19:33 volumio4 go-librespot[1880]: time="2026-08-26T14:19:33+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:19:33 volumio4 go-librespot[1880]: time="2026-08-26T14:19:33+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:33 volumio4 go-librespot[1880]: time="2026-08-26T14:19:33+02:00" level=debug msg="completed challenge" Aug 26 14:19:33 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:33 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:33 volumio4 volumio[1249]: info: Initializing connection to go-librespot Websocket Aug 26 14:19:33 volumio4 go-librespot[1880]: time="2026-08-26T14:19:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:33 volumio4 go-librespot[1880]: time="2026-08-26T14:19:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:33 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:33 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:19:34 volumio4 volumio[1249]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 14:19:34 volumio4 volumio[1249]: info: touch_display: Setting screensaver timeout to 20 seconds. Aug 26 14:19:35 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Aug 26 14:19:35 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Aug 26 14:19:35 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Aug 26 14:19:35 volumio4 volumio[1249]: 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: 16 Aug 26 14:19:36 volumio4 volumio[1249]: 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: 16 Aug 26 14:19:36 volumio4 volumio[1249]: info: Received Get System Info Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 14:19:36 volumio4 volumio[1249]: info: Discovery: Getting this device information Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:36 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 14:19:36 volumio4 volumio-remote-updater[729]: [2026-08-26 14:19:36] [connect] Successful connection Aug 26 14:19:36 volumio4 volumio5-onboarding[1850]: time=2026-08-26T14:19:36.315+02:00 level=INFO msg="system info for 157c329da90c2b594996e463c017e028" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Aug 26 14:19:36 volumio4 volumio5-onboarding[1850]: time=2026-08-26T14:19:36.353+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 26 14:19:36 volumio4 volumio[1249]: info: Received Get System Info Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 14:19:36 volumio4 volumio[1249]: info: Discovery: Getting this device information Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:36 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:36 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 14:19:36 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.80 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Aug 26 14:19:37 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 14:19:37 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:37 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:37 volumio4 go-librespot[2047]: go-librespot daemon starting... Aug 26 14:19:37 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Aug 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+02:00" level=debug msg="app state loaded" Aug 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+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 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+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 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+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 26 14:19:37 volumio4 go-librespot[2054]: time="2026-08-26T14:19:37+02:00" level=info msg="zeroconf server listening on port 42017" Aug 26 14:19:38 volumio4 volumio[1249]: info: Initializing connection to go-librespot Websocket Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="obtained new client token: AAF+URjWlxD+0obWaQC0E+beEo+G8RDw8uvPcbGSzTfH6wyk3rPG/KjDbKO+jsCdmkSZt6lIGv33tjnDC6fgkEVlS/4xytEk7M3nl+qxbUsNiSpA1tfBJRzufEYEAuWeTru3EQYi1TQJhuf+rLglsE8LbLg8PagomqgzOwZw7CMkG08L6nREdxD75/zFz6kPJGC5WvLSJtudHhM58VCxd4BK0Q+6uqz6BVo2lJ0i/65LN3bIX14fWw==" Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="completed challenge" Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:38 volumio4 volumio-remote-updater[729]: [2026-08-26 14:19:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787746776 101 Aug 26 14:19:38 volumio4 volumio[1249]: 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: 19 Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="new websocket client" Aug 26 14:19:38 volumio4 go-librespot[2054]: time="2026-08-26T14:19:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:39 volumio4 volumio[1249]: info: Connection to go-librespot Websocket established Aug 26 14:19:39 volumio4 volumio[1249]: SPOTIFY: User informations: {"account_id":"mRGRd5RND0","country":"NL","display_name":"mennogroeneveld","email":"mennogroeneveld@ziggo.nl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/mennogroeneveld"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/mennogroeneveld","id":"mennogroeneveld","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee854048f9e4fee477eca715f4ec","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b824048f9e4fee477eca715f4ec","width":64}],"product":"premium","type":"user","uri":"spotify:user:mennogroeneveld"} Aug 26 14:19:39 volumio4 volumio[1249]: info: Spotify Successfully logged in Aug 26 14:19:39 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 14:19:39 volumio4 volumio[1249]: info: [1787746779674] CoreMusicLibrary::Adding element Spotify Aug 26 14:19:39 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 14:19:39 volumio4 volumio[1249]: Cannot find translation for source Spotify Aug 26 14:19:39 volumio4 go-librespot[2054]: time="2026-08-26T14:19:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.166:39924->34.158.1.133:443: read: connection reset by peer" Aug 26 14:19:40 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 26 14:19:40 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:19:40 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:19:40 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Aug 26 14:19:40 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 14:19:40 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:40 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 14:19:40 volumio4 go-librespot[2054]: time="2026-08-26T14:19:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 14:19:40 volumio4 go-librespot[2054]: time="2026-08-26T14:19:40+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:40 volumio4 go-librespot[2054]: time="2026-08-26T14:19:40+02:00" level=debug msg="completed challenge" Aug 26 14:19:40 volumio4 go-librespot[2054]: time="2026-08-26T14:19:40+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 14:19:40 volumio4 volumio[1249]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 14:19:40 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 14:19:41 volumio4 go-librespot[2054]: time="2026-08-26T14:19:41+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 14:19:41 volumio4 go-librespot[2054]: time="2026-08-26T14:19:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 14:19:42 volumio4 go-librespot[2054]: time="2026-08-26T14:19:42+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:42 volumio4 go-librespot[2054]: time="2026-08-26T14:19:42+02:00" level=debug msg="completed challenge" Aug 26 14:19:42 volumio4 go-librespot[2054]: time="2026-08-26T14:19:42+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:43 volumio4 go-librespot[2054]: time="2026-08-26T14:19:43+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:19:43 volumio4 go-librespot[2054]: time="2026-08-26T14:19:43+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:43 volumio4 go-librespot[2054]: time="2026-08-26T14:19:43+02:00" level=debug msg="completed challenge" Aug 26 14:19:43 volumio4 go-librespot[2054]: time="2026-08-26T14:19:43+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:44 volumio4 go-librespot[2054]: time="2026-08-26T14:19:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:44 volumio4 go-librespot[2054]: time="2026-08-26T14:19:44+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:44 volumio4 go-librespot[2054]: time="2026-08-26T14:19:44+02:00" level=debug msg="completed challenge" Aug 26 14:19:44 volumio4 go-librespot[2054]: time="2026-08-26T14:19:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:44 volumio4 go-librespot[2054]: time="2026-08-26T14:19:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:44 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:44 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:19:47 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 26 14:19:47 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:47 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:47 volumio4 go-librespot[2129]: go-librespot daemon starting... Aug 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+02:00" level=debug msg="app state loaded" Aug 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+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 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+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 26 14:19:47 volumio4 go-librespot[2130]: time="2026-08-26T14:19:47+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 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=info msg="zeroconf server listening on port 36607" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=debug msg="obtained new client token: AAHPrXA02cHvR+vIf8foH/0KnJUfRPtEut1riWrAjpkvsZCCb7KmycTb5ayuBMEz+oJaNVXDeB1Ssdu7mHsyASVphce3HKv+wxU+FTJSOnC4rwDQUZxnv3m40uY5kVyKkaLj5JdS6Q8TvwZj9usA1CIDF5xk5ET0AkcjT6Jy1CA2qkezIacbeS3HjkX6tUI2fa9f7tEEtpFTNDWZP9mVd2iljnpn5cqqD2l07IzJKW2R/fugT0CuVQ==" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=debug msg="completed challenge" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:48 volumio4 go-librespot[2130]: time="2026-08-26T14:19:48+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:19:49 volumio4 go-librespot[2130]: time="2026-08-26T14:19:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:19:49 volumio4 go-librespot[2130]: time="2026-08-26T14:19:49+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:49 volumio4 go-librespot[2130]: time="2026-08-26T14:19:49+02:00" level=debug msg="completed challenge" Aug 26 14:19:49 volumio4 go-librespot[2130]: time="2026-08-26T14:19:49+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:50 volumio4 go-librespot[2130]: time="2026-08-26T14:19:50+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 14:19:50 volumio4 go-librespot[2130]: time="2026-08-26T14:19:50+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:50 volumio4 go-librespot[2130]: time="2026-08-26T14:19:50+02:00" level=debug msg="completed challenge" Aug 26 14:19:50 volumio4 go-librespot[2130]: time="2026-08-26T14:19:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:51 volumio4 go-librespot[2130]: time="2026-08-26T14:19:51+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 26 14:19:51 volumio4 go-librespot[2130]: time="2026-08-26T14:19:51+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:51 volumio4 go-librespot[2130]: time="2026-08-26T14:19:51+02:00" level=debug msg="completed challenge" Aug 26 14:19:51 volumio4 go-librespot[2130]: time="2026-08-26T14:19:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:52 volumio4 go-librespot[2130]: time="2026-08-26T14:19:52+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:19:52 volumio4 go-librespot[2130]: time="2026-08-26T14:19:52+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:52 volumio4 go-librespot[2130]: time="2026-08-26T14:19:52+02:00" level=debug msg="completed challenge" Aug 26 14:19:52 volumio4 go-librespot[2130]: time="2026-08-26T14:19:52+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:52 volumio4 go-librespot[2130]: time="2026-08-26T14:19:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:52 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:19:52 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:19:55 volumio4 volumio[1249]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 14:19:55 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 14:19:55 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:55 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 14:19:55 volumio4 volumio[1249]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 14:19:55 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 26 14:19:55 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:56 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:19:56 volumio4 go-librespot[2153]: go-librespot daemon starting... Aug 26 14:19:56 volumio4 volumio[1249]: info: MyVolumio login type: Token Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=debug msg="app state loaded" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+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 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+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 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+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 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=info msg="zeroconf server listening on port 36161" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=debug msg="obtained new client token: AAEya3b8l/so3keRbVeuNacmMQ1vYZwvNeWKBUKLBflPwAGjDrt2QXdkqzf5I3FRCsvxHSqhpm/eFocjVNs1sbh8vA84v/vJwO5QV5MDyRo1dOKyG3GyO6TrBljUpNK4UxkTovqQq6+X8XtraY3m69RKYahZiNkDv4WwSaDQT3WshEuPowwh84i6dD37pda7TvJlpt4N2gKBOGo6RR/0jMBxXCRDRlMuBre+K7SilfgGCatm7E1y5sDE" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:19:56 volumio4 volumio[1249]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 14:19:56 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=debug msg="completed challenge" Aug 26 14:19:56 volumio4 go-librespot[2154]: time="2026-08-26T14:19:56+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:57 volumio4 go-librespot[2154]: time="2026-08-26T14:19:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:19:57 volumio4 go-librespot[2154]: time="2026-08-26T14:19:57+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:57 volumio4 go-librespot[2154]: time="2026-08-26T14:19:57+02:00" level=debug msg="completed challenge" Aug 26 14:19:57 volumio4 go-librespot[2154]: time="2026-08-26T14:19:57+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:58 volumio4 go-librespot[2154]: time="2026-08-26T14:19:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:19:58 volumio4 go-librespot[2154]: time="2026-08-26T14:19:58+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:19:58 volumio4 go-librespot[2154]: time="2026-08-26T14:19:58+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 14:19:58 volumio4 go-librespot[2154]: time="2026-08-26T14:19:58+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:58 volumio4 go-librespot[2154]: time="2026-08-26T14:19:58+02:00" level=debug msg="completed challenge" Aug 26 14:19:59 volumio4 go-librespot[2154]: time="2026-08-26T14:19:59+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:19:59 volumio4 go-librespot[2154]: time="2026-08-26T14:19:59+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 26 14:19:59 volumio4 go-librespot[2154]: time="2026-08-26T14:19:59+02:00" level=debug msg="completed keyexchange" Aug 26 14:19:59 volumio4 go-librespot[2154]: time="2026-08-26T14:19:59+02:00" level=debug msg="completed challenge" Aug 26 14:20:00 volumio4 go-librespot[2154]: time="2026-08-26T14:20:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:00 volumio4 go-librespot[2154]: time="2026-08-26T14:20:00+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:20:01 volumio4 go-librespot[2154]: time="2026-08-26T14:20:01+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:01 volumio4 go-librespot[2154]: time="2026-08-26T14:20:01+02:00" level=debug msg="completed challenge" Aug 26 14:20:01 volumio4 go-librespot[2154]: time="2026-08-26T14:20:01+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:01 volumio4 go-librespot[2154]: time="2026-08-26T14:20:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:01 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:01 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:20:04 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 26 14:20:04 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:04 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:04 volumio4 go-librespot[2177]: go-librespot daemon starting... Aug 26 14:20:04 volumio4 go-librespot[2178]: time="2026-08-26T14:20:04+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:20:04 volumio4 go-librespot[2178]: time="2026-08-26T14:20:04+02:00" level=debug msg="app state loaded" Aug 26 14:20:04 volumio4 go-librespot[2178]: time="2026-08-26T14:20:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+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 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+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 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+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 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+02:00" level=info msg="zeroconf server listening on port 36997" Aug 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+02:00" level=debug msg="obtained new client token: AAHnegsYnjLbwxEjyIhh37/R0abeViHhCwL23ZOyzXN9NlwpjhwBQOt8Y4h09/BYxV5R2KoouHj5dhO+XOvceUzOuZyx8N3T2nTbGSeWxBryp3tpJtt35u3wwyEnvafQUZwa8chvv+57PA0u6+zQeLJuBD3+8LJspt+I8nFbCdqRbw3j8wHXbIa7HFlDPa/ltPpR3CdxwKsLxExrnR+oxbTf5qoBqYgPp78YVTXYfcu7twwsiIoa15Lw" Aug 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:05 volumio4 go-librespot[2178]: time="2026-08-26T14:20:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:20:06 volumio4 go-librespot[2178]: time="2026-08-26T14:20:06+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:06 volumio4 go-librespot[2178]: time="2026-08-26T14:20:06+02:00" level=debug msg="completed challenge" Aug 26 14:20:06 volumio4 go-librespot[2178]: time="2026-08-26T14:20:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:06 volumio4 volumio5-onboarding[1850]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Aug 26 14:20:06 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:06 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 14:20:06 volumio4 go-librespot[2178]: time="2026-08-26T14:20:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:20:06 volumio4 go-librespot[2178]: time="2026-08-26T14:20:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:06 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Aug 26 14:20:06 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:06 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:06 volumio4 volumio5-onboarding[2187]: time=2026-08-26T14:20:06.880+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:20:07 volumio4 go-librespot[2178]: time="2026-08-26T14:20:07+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 14:20:07 volumio4 go-librespot[2178]: time="2026-08-26T14:20:07+02:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Aug 26 14:20:07 volumio4 go-librespot[2178]: time="2026-08-26T14:20:07+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:20:07 volumio4 go-librespot[2178]: time="2026-08-26T14:20:07+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:07 volumio4 go-librespot[2178]: time="2026-08-26T14:20:07+02:00" level=debug msg="completed challenge" Aug 26 14:20:08 volumio4 go-librespot[2178]: time="2026-08-26T14:20:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:08 volumio4 go-librespot[2178]: time="2026-08-26T14:20:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:08 volumio4 go-librespot[2178]: time="2026-08-26T14:20:08+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:08 volumio4 go-librespot[2178]: time="2026-08-26T14:20:08+02:00" level=debug msg="completed challenge" Aug 26 14:20:08 volumio4 go-librespot[2178]: time="2026-08-26T14:20:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:09 volumio4 go-librespot[2178]: time="2026-08-26T14:20:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:20:09 volumio4 go-librespot[2178]: time="2026-08-26T14:20:09+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:09 volumio4 go-librespot[2178]: time="2026-08-26T14:20:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:09 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:09 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:20:10 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 14:20:10 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 14:20:10 volumio4 volumio[1249]: info: Streaming services startup Aug 26 14:20:10 volumio4 volumio[1249]: info: Starting Streaming Daemon Aug 26 14:20:11 volumio4 sudo[2211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 14:20:11 volumio4 sudo[2211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:20:11 volumio4 sudo[2211]: pam_unix(sudo:session): session closed for user root Aug 26 14:20:11 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 14:20:12 volumio4 volumio[1249]: info: Discovery: Disconnected from remote: 192.168.1.242 Aug 26 14:20:12 volumio4 volumio[1249]: info: Discovery: Disconnected from remote: 192.168.1.80 Aug 26 14:20:12 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 26 14:20:12 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:12 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:12 volumio4 go-librespot[2217]: go-librespot daemon starting... Aug 26 14:20:12 volumio4 go-librespot[2218]: time="2026-08-26T14:20:12+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:20:12 volumio4 go-librespot[2218]: time="2026-08-26T14:20:12+02:00" level=debug msg="app state loaded" Aug 26 14:20:12 volumio4 go-librespot[2218]: time="2026-08-26T14:20:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:20:12 volumio4 volumio[1249]: info: Getting Spotify volume Aug 26 14:20:12 volumio4 volumio[1249]: info: Discovery: Connecting to remote: 192.168.1.80 Aug 26 14:20:12 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+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 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+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 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+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 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+02:00" level=info msg="zeroconf server listening on port 32873" Aug 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+02:00" level=debug msg="obtained new client token: AAHQ+F67/l22mtfb0PXeojrKOdf2JhWiDVvuFxc4kgeeZt8ZG1vvhohBIlS4QDKJN1MXeOcpfRTRqQypofGJSOIgV0epPVyhvewe1Xqs3DrMHqeuNtxnTIbdzp+wXWs42PgLgNvP9E1QIYd9lEs6/uLAkx7ScmEyzhJa5RL8N+nPZovTvqxnkm0N61BQKExLmWjB0+J3zXEbo0ySiuZ7XL4KNFOcmKviCLteo8/VBJNQC5s2wM/BQqzj" Aug 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:13 volumio4 go-librespot[2218]: time="2026-08-26T14:20:13+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:13 volumio4 volumio[1249]: info: Connection to go-librespot Websocket closed Aug 26 14:20:13 volumio4 volumio[1249]: error: Cannot start Volumio Streaming Daemon Aug 26 14:20:13 volumio4 volumio[1249]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 14:20:13 volumio4 volumio[1249]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 14:20:13 volumio4 volumio[1249]: error: An error occurred while listing Spotify featured playlists Error: Client network socket disconnected before secure TLS connection was established Aug 26 14:20:13 volumio4 volumio[1249]: info: An error occurred while getting Spotify ROOT Discover Folders: Aug 26 14:20:13 volumio4 volumio[1249]: error: An error occurred while listing Spotify new albums Error: Client network socket disconnected before secure TLS connection was established Aug 26 14:20:13 volumio4 volumio[1249]: error: An error occurred while listing Spotify categories Error: Client network socket disconnected before secure TLS connection was established Aug 26 14:20:13 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:20:13 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:20:13 volumio4 volumio[1249]: info: Discovery: Connected to remote: 192.168.1.80 Aug 26 14:20:14 volumio4 go-librespot[2218]: time="2026-08-26T14:20:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:20:14 volumio4 go-librespot[2218]: time="2026-08-26T14:20:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:14 volumio4 go-librespot[2218]: time="2026-08-26T14:20:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:20:14 volumio4 go-librespot[2218]: time="2026-08-26T14:20:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:15 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 14:20:15 volumio4 volumio[1249]: info: Discovery: Getting this device information Aug 26 14:20:15 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Aug 26 14:20:15 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Aug 26 14:20:15 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 14:20:15 volumio4 go-librespot[2218]: time="2026-08-26T14:20:15+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 14:20:15 volumio4 go-librespot[2218]: time="2026-08-26T14:20:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 14:20:15 volumio4 go-librespot[2218]: time="2026-08-26T14:20:15+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:15 volumio4 go-librespot[2218]: time="2026-08-26T14:20:15+02:00" level=debug msg="completed challenge" Aug 26 14:20:15 volumio4 go-librespot[2218]: time="2026-08-26T14:20:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:16 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Aug 26 14:20:16 volumio4 go-librespot[2218]: time="2026-08-26T14:20:16+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetBrowseSources Aug 26 14:20:16 volumio4 go-librespot[2218]: time="2026-08-26T14:20:16+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:16 volumio4 go-librespot[2218]: time="2026-08-26T14:20:16+02:00" level=debug msg="completed challenge" Aug 26 14:20:16 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 14:20:16 volumio4 go-librespot[2218]: time="2026-08-26T14:20:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:16 volumio4 volumio5-onboarding[2187]: 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:36278->127.0.0.1:3000: i/o timeout Aug 26 14:20:16 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:16 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 14:20:16 volumio4 volumio[1249]: error: MyVolumio Custom Token format not valid, refreshing it Aug 26 14:20:17 volumio4 volumio[1249]: verbose: New Socket.io Connection to 192.168.1.166:3000 from 192.168.1.242 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Aug 26 14:20:17 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4. Aug 26 14:20:17 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:17 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:17 volumio4 volumio5-onboarding[2227]: time=2026-08-26T14:20:17.274+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:20:17 volumio4 go-librespot[2218]: time="2026-08-26T14:20:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:17 volumio4 go-librespot[2218]: time="2026-08-26T14:20:17+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:17 volumio4 go-librespot[2218]: time="2026-08-26T14:20:17+02:00" level=debug msg="completed challenge" Aug 26 14:20:17 volumio4 go-librespot[2218]: time="2026-08-26T14:20:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:17 volumio4 go-librespot[2218]: time="2026-08-26T14:20:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:17 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:17 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:20:17 volumio4 volumio[1249]: info: Discovery: Connected to remote: 192.168.1.242 Aug 26 14:20:17 volumio4 volumio[1249]: info: Initializing connection to go-librespot Websocket Aug 26 14:20:18 volumio4 volumio[1249]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 14:20:18 volumio4 volumio[1249]: Error: socket hang up Aug 26 14:20:18 volumio4 volumio[1249]: at connResetException (node:internal/errors:720:14) Aug 26 14:20:18 volumio4 volumio[1249]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 26 14:20:18 volumio4 volumio[1249]: at Socket.emit (node:events:526:35) Aug 26 14:20:18 volumio4 volumio[1249]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 26 14:20:18 volumio4 volumio[1249]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 26 14:20:18 volumio4 volumio[1249]: code: 'ECONNRESET', Aug 26 14:20:18 volumio4 volumio[1249]: response: undefined Aug 26 14:20:18 volumio4 volumio[1249]: } Aug 26 14:20:18 volumio4 volumio[1249]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 14:20:20 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 26 14:20:20 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:20 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:20 volumio4 go-librespot[2261]: go-librespot daemon starting... Aug 26 14:20:20 volumio4 go-librespot[2262]: time="2026-08-26T14:20:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:20:20 volumio4 go-librespot[2262]: time="2026-08-26T14:20:20+02:00" level=debug msg="app state loaded" Aug 26 14:20:20 volumio4 go-librespot[2262]: time="2026-08-26T14:20:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+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 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+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 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+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 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+02:00" level=info msg="zeroconf server listening on port 46689" Aug 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+02:00" level=debug msg="obtained new client token: AAE5B3zGPqKoQGkV13jFdwLonYCU9yEO54Pmyt2d4RyId330agp5C4RQb7IjZ34hV0uAOGhxl/qb7l/1VEgMJlNl9Nd64U4kadCUEm/CX4EidD/4bl/JCVNVeUBoRISLzU6PGTCrxg2m0a5Xma1fsETWtjjLulZlFkWEoAzV6njvbBifScHnTltUqUsBf3NAtROWSWZA9RBSrzAyNOcRq6yqmHcxFCs/LPkVdw8qkZE4+nBx8B97NRpS" Aug 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:21 volumio4 go-librespot[2262]: time="2026-08-26T14:20:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="completed challenge" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:22 volumio4 go-librespot[2262]: time="2026-08-26T14:20:22+02:00" level=debug msg="completed challenge" Aug 26 14:20:23 volumio4 go-librespot[2262]: time="2026-08-26T14:20:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:23 volumio4 go-librespot[2262]: time="2026-08-26T14:20:23+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 14:20:23 volumio4 go-librespot[2262]: time="2026-08-26T14:20:23+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:23 volumio4 go-librespot[2262]: time="2026-08-26T14:20:23+02:00" level=debug msg="completed challenge" Aug 26 14:20:23 volumio4 go-librespot[2262]: time="2026-08-26T14:20:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:24 volumio4 go-librespot[2262]: time="2026-08-26T14:20:24+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 26 14:20:24 volumio4 go-librespot[2262]: time="2026-08-26T14:20:24+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:24 volumio4 go-librespot[2262]: time="2026-08-26T14:20:24+02:00" level=debug msg="completed challenge" Aug 26 14:20:24 volumio4 go-librespot[2262]: time="2026-08-26T14:20:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:25 volumio4 go-librespot[2262]: time="2026-08-26T14:20:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Aug 26 14:20:25 volumio4 go-librespot[2262]: time="2026-08-26T14:20:25+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:25 volumio4 go-librespot[2262]: time="2026-08-26T14:20:25+02:00" level=debug msg="completed challenge" Aug 26 14:20:25 volumio4 go-librespot[2262]: time="2026-08-26T14:20:25+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:25 volumio4 go-librespot[2262]: time="2026-08-26T14:20:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:25 volumio4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:25 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 14:20:27 volumio4 volumio5-onboarding[2227]: 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:50800->127.0.0.1:3000: i/o timeout Aug 26 14:20:27 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 14:20:27 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 14:20:27 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 5. Aug 26 14:20:27 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:27 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 14:20:27 volumio4 volumio5-onboarding[2271]: time=2026-08-26T14:20:27.526+02:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Aug 26 14:20:28 volumio4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 26 14:20:28 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:28 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 14:20:28 volumio4 go-librespot[2281]: go-librespot daemon starting... Aug 26 14:20:28 volumio4 go-librespot[2283]: time="2026-08-26T14:20:28+02:00" level=info msg="running go-librespot 0.6.2" Aug 26 14:20:28 volumio4 go-librespot[2283]: time="2026-08-26T14:20:28+02:00" level=debug msg="app state loaded" Aug 26 14:20:28 volumio4 go-librespot[2283]: time="2026-08-26T14:20:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 14:20:29 volumio4 sudo[2282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 14:19' Aug 26 14:20:29 volumio4 sudo[2282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+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 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+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 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+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 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=info msg="zeroconf server listening on port 41541" Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=debug msg="obtained new client token: AAEZ3zz6gVllLrZ1e0M6+jO/es+EYfbCwQxbv73L5Wm/Wu7W0jRGjQkGyotcgceDG6rkxfSv47fjybqpQ/4VSDGUpabXq0ZQo/PVug0xP3kCk0mCMpfkSHQrefKyp+Yo7egV7HMTJ6a7P5wx14VfNvIHQC+uTagsi3dKFj3b4MBAbmN+Z0ZmxIJz5vniCWm8hvqO9hTW8PgSV0F4p8TusUaC8pH2IZ4AO7+9dlzaUgr6AfhgkTumPUUi" Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=debug msg="completed keyexchange" Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=debug msg="completed challenge" Aug 26 14:20:29 volumio4 go-librespot[2283]: time="2026-08-26T14:20:29+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Aug 26 14:20:30 volumio4 go-librespot[2283]: time="2026-08-26T14:20:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"