Aug 29 14:52:00 volumio volumio[1243]: info: Asound.conf file unchanged, so no further update is needed Aug 29 14:52:00 volumio volumio[1243]: info: Output device has changed, restarting MPD Aug 29 14:52:00 volumio volumio[1395]: Starting albumart workers Aug 29 14:52:01 volumio volumio[1243]: info: Output device has changed, restarting Shairport Sync Aug 29 14:52:01 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:01 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:01 volumio sudo[1477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 14:52:01 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:01 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:01 volumio sudo[1479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 14:52:01 volumio sudo[1479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:01 volumio volumio[1243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:52:01 volumio volumio[1243]: info: ___________ START PLUGINS ___________ Aug 29 14:52:01 volumio volumio[1397]: Starting albumart workers Aug 29 14:52:01 volumio volumio[1396]: Starting albumart workers Aug 29 14:52:01 volumio volumio[1243]: info: ControllerMpd::onStart: Initializing MPD Aug 29 14:52:01 volumio volumio[1243]: info: Creating MPD Configuration file Aug 29 14:52:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 14:52:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 14:52:02 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 14:52:02 volumio volumio[1243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:52:02 volumio volumio[1243]: info: [1788011522307] CoreMusicLibrary::Adding element Servidores multimédia Aug 29 14:52:02 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:52:02 volumio sudo[1488]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 14:52:02 volumio sudo[1488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 14:52:02 volumio sudo[1494]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 14:52:02 volumio sudo[1488]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:02 volumio sudo[1489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 14:52:02 volumio sudo[1489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:02 volumio sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 14:52:02 volumio sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Aug 29 14:52:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 14:52:02 volumio sudo[1493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 14:52:02 volumio sudo[1493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 14:52:02 volumio volumio[1243]: info: UPNP Browser: Client initialized successfully Aug 29 14:52:02 volumio sudo[1491]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:02 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:02 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:02 volumio sudo[1474]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:03 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:52:03 volumio sudo[1489]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:03 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 29 14:52:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 14:52:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 29 14:52:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 14:52:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 14:52:03 volumio volumio[1243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 14:52:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 14:52:03 volumio volumio[1243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:52:03 volumio volumio[1243]: info: [1788011523885] CoreMusicLibrary::Adding element Last_100 Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:52:03 volumio sudo[1518]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 14:52:03 volumio sudo[1518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:52:03 volumio volumio[1243]: info: [1788011523974] CoreMusicLibrary::Adding element Webradio Aug 29 14:52:03 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:52:03 volumio sudo[1526]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 14:52:03 volumio sudo[1518]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:04 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:52:04 volumio volumio[1243]: info: Initializing BBC Radios Aug 29 14:52:04 volumio volumio5-onboarding[1509]: time=2026-08-29T14:52:04.294+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 14:52:04 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:52:04 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:05 volumio volumio[1243]: info: Creating Spotify config file Aug 29 14:52:05 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:12 volumio volumio[1243]: info: [ytcr] Data store TTL expired - clearing it... Aug 29 14:52:13 volumio volumio[1243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:52:13 volumio volumio[1243]: info: [1788011533501] CoreMusicLibrary::Adding element YouTube Music Aug 29 14:52:13 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:52:13 volumio volumio[1243]: Cannot find translation for source YouTube Music Aug 29 14:52:13 volumio volumio[1243]: info: GPIOButtonLED: Starting plugin Aug 29 14:52:14 volumio volumio[1243]: info: Volumio Calling Home Aug 29 14:52:14 volumio volumio5-onboarding[1509]: 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:42716->127.0.0.1:3000: i/o timeout Aug 29 14:52:14 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:14 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 14:52:14 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 14:52:14 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:52:14 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:52:14 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:14.887+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 14:52:15 volumio mpd[1527]: 2026-08-29T14:52:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 14:52:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 14:52:15 volumio sudo[1479]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:15 volumio sudo[1493]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:17 volumio volumio[1243]: info: MPD Permissions set Aug 29 14:52:17 volumio volumio[1243]: info: MPD Permissions set Aug 29 14:52:17 volumio volumio[1243]: info: Upmpdcli Daemon Started Aug 29 14:52:18 volumio volumio[1243]: info: Volumio called home Aug 29 14:52:18 volumio volumio[1243]: info: Spotify config file written Aug 29 14:52:18 volumio sudo[1610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 14:52:18 volumio sudo[1610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:18 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:52:18 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:52:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:18 volumio go-librespot[1612]: go-librespot daemon starting... Aug 29 14:52:18 volumio sudo[1610]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:19 volumio go-librespot[1613]: time="2026-08-29T14:52:19+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:19 volumio go-librespot[1613]: time="2026-08-29T14:52:19+01:00" level=debug msg="app state loaded" Aug 29 14:52:19 volumio go-librespot[1613]: time="2026-08-29T14:52:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:20 volumio volumio[1243]: error: MPD error: The expression evaluated to a falsy value: Aug 29 14:52:20 volumio volumio[1243]: assert.ok(self.idling) Aug 29 14:52:20 volumio volumio[1243]: error: The expression evaluated to a falsy value: Aug 29 14:52:20 volumio volumio[1243]: assert.ok(self.idling) Aug 29 14:52:20 volumio volumio[1243]: 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: 3 Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=info msg="zeroconf server listening on port 42657" Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:20 volumio volumio[1243]: info: MPD running with PID1527 Aug 29 14:52:20 volumio volumio[1243]: ,establishing connection Aug 29 14:52:20 volumio volumio[1243]: info: GPIOButtonLED: dtoverlay already correct Aug 29 14:52:20 volumio volumio[1243]: info: GPIOButtonLED: LED+ on GPIO 22 Aug 29 14:52:20 volumio volumio[1243]: info: GPIOButtonLED: LED- on GPIO 4 Aug 29 14:52:20 volumio volumio[1243]: info: GPIOButtonLED: LED polarity = normal Aug 29 14:52:20 volumio volumio[1243]: info: GPIOButtonLED: LED blink slow Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:20 volumio go-librespot[1613]: time="2026-08-29T14:52:20+01:00" level=debug msg="obtained new client token: AAGu+/ir9IrEyBcgJrjIeUzzPptuAMN+k5o+fPIwn8r2qPXoE7FG+UEu0tkAlf9kjJ+13ksN1omrz4l4FUFMTf/lcd3IdpnHkto64QM4QgB3OkoIuTcHu/gn5Uo01yNphELxw1gy9Xyoo3Q0uMBzGFTTxgVQSgEaPQhGKy7C6Kqu3H3u2jmPWgh0pyn/sXlLc5n6xaiMxwgoOhZLeMhRZpCN+Oase3iGfvACnkOE4NkMutDitZ82YdyiDA==" Aug 29 14:52:21 volumio go-librespot[1613]: time="2026-08-29T14:52:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:21 volumio go-librespot[1613]: time="2026-08-29T14:52:21+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:21 volumio go-librespot[1613]: time="2026-08-29T14:52:21+01:00" level=debug msg="completed challenge" Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio go-librespot[1613]: time="2026-08-29T14:52:21+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:52:21 volumio volumio[1243]: info: No need to fix Spotify hosts Aug 29 14:52:21 volumio go-librespot[1613]: time="2026-08-29T14:52:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:21 volumio volumio[1243]: error: updateQueue error: null Aug 29 14:52:22 volumio volumio[1243]: 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: 3 Aug 29 14:52:22 volumio volumio[1243]: info: Received Get System Info Aug 29 14:52:22 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 14:52:22 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 14:52:22 volumio volumio[1243]: info: Discovery: Getting this device information Aug 29 14:52:22 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:52:22 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:22 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:52:22 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:22.331+01:00 level=INFO msg="system info for 4ae804b282082777957189fce586290e" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 14:52:22 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:22.387+01:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 14:52:23 volumio volumio[1243]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 29 14:52:23 volumio volumio[1243]: info: GPIOButtonLED: Boot complete - LED solid Aug 29 14:52:23 volumio volumio[1243]: info: Received Get System Info Aug 29 14:52:23 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 14:52:23 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 14:52:23 volumio volumio[1243]: info: Discovery: Getting this device information Aug 29 14:52:23 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:52:23 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:23 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:52:23 volumio volumio[1243]: info: New Spotify access tokenBQDIAM1NLQ... Aug 29 14:52:23 volumio volumio[1243]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 14:52:24 volumio volumio-remote-updater[700]: Test mode disabled Aug 29 14:52:24 volumio volumio-remote-updater[700]: Alpha mode disabled Aug 29 14:52:24 volumio volumio-remote-updater[700]: Alpha legacy test mode disabled Aug 29 14:52:24 volumio volumio[1243]: error: updateQueue error: null Aug 29 14:52:24 volumio volumio[1243]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 14:52:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 14:52:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:24 volumio go-librespot[1637]: go-librespot daemon starting... Aug 29 14:52:24 volumio go-librespot[1638]: time="2026-08-29T14:52:24+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:24 volumio go-librespot[1638]: time="2026-08-29T14:52:24+01:00" level=debug msg="app state loaded" Aug 29 14:52:24 volumio go-librespot[1638]: time="2026-08-29T14:52:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=info msg="zeroconf server listening on port 41881" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=debug msg="obtained new client token: AAEBauLUJ3PmAM++7CSTn0jyfd+k53ncK6KDUUW5U27uhlctteL2f8lDRfD2/H7AeQWPnwLJ6T9VGnAxznMy41AAQgTKwh1T1s6KsN5z7X3hh74D9ETYWown9CfKF0ih3lUb451EmqCQ8kYH+aPyOTK9yEAyNZ1AwWTd7BKh92Hm5UMtqTCtzmIcORj8QvZUfeSMd5ZPRTHaEoHiWVfvwo44/t+4w9zWk6d/2XrcJzute+yTLZvyb9oeuA==" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 29 14:52:25 volumio go-librespot[1638]: time="2026-08-29T14:52:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 29 14:52:26 volumio go-librespot[1638]: time="2026-08-29T14:52:26+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:26 volumio go-librespot[1638]: time="2026-08-29T14:52:26+01:00" level=debug msg="completed challenge" Aug 29 14:52:26 volumio volumio[1243]: info: Starting Shairport Sync Aug 29 14:52:26 volumio go-librespot[1638]: time="2026-08-29T14:52:26+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:26 volumio volumio[1243]: info: Starting Shairport Sync Aug 29 14:52:26 volumio volumio[1243]: info: Starting Shairport Sync Aug 29 14:52:26 volumio sudo[1648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:52:26 volumio sudo[1648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:26 volumio go-librespot[1638]: time="2026-08-29T14:52:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:26 volumio sudo[1650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:52:26 volumio sudo[1650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:52:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:52:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:26 volumio systemd[1]: shairport-sync.service: Consumed 2.602s CPU time. Aug 29 14:52:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:26 volumio sudo[1648]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:26 volumio sudo[1652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:52:26 volumio sudo[1652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:52:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:52:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:52:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:26 volumio sudo[1650]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:52:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:52:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:52:27 volumio sudo[1652]: pam_unix(sudo:session): session closed for user root Aug 29 14:52:27 volumio volumio[1243]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 14:52:27 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 14:52:27 volumio volumio[1243]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 29 14:52:27 volumio volumio[1243]: info: go-librespot daemon successfully initialized Aug 29 14:52:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 14:52:28 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:28.544+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 29 14:52:28 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:28.549+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 29 14:52:28 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:28.550+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 29 14:52:28 volumio volumio[1243]: info: Shairport-Sync Started Aug 29 14:52:28 volumio volumio[1243]: Error adding Membership: Error: addMembership EINVAL Aug 29 14:52:28 volumio volumio[1243]: info: Shairport-Sync Started Aug 29 14:52:28 volumio volumio[1243]: info: Shairport-Sync Started Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 14:52:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 14:52:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:29 volumio go-librespot[1688]: go-librespot daemon starting... Aug 29 14:52:29 volumio go-librespot[1689]: time="2026-08-29T14:52:29+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:29 volumio go-librespot[1689]: time="2026-08-29T14:52:29+01:00" level=debug msg="app state loaded" Aug 29 14:52:29 volumio volumio[1243]: info: Received Get System Info Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 14:52:29 volumio go-librespot[1689]: time="2026-08-29T14:52:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:29 volumio volumio[1243]: info: Discovery: Getting this device information Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:52:29 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 14:52:29 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 14:52:29 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:29.993+01:00 level=INFO msg="enabling local network discovery" Aug 29 14:52:30 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:30.059+01:00 level=INFO msg="enabling BLE discovery" Aug 29 14:52:30 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:52:30 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=info msg="zeroconf server listening on port 44339" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="obtained new client token: AAGdCMWRAcuBk4rms4RJcw26ukVnTyoRfDNDTL9nD7HrbYJKW5Sce9GUp0P+jqmYBdraJ+YlE27eQg6xGZv2/SpZezdjd2+gSr7Pe5U3Td9llu+iLLUf0g6UN419kj4pxOfoZltYNV0zW2m+IYSZbwBJeMC9W0QQOe4vKXLEDj8luuPt7j4ZiR6Jl5AKuOypARdCEl75dlha7BG6NCfX/a4gKvPHjVBhJ3bbnRVlL/2D9w6seD8965evRg==" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:30 volumio go-librespot[1689]: time="2026-08-29T14:52:30+01:00" level=debug msg="completed challenge" Aug 29 14:52:30 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:31 volumio go-librespot[1689]: time="2026-08-29T14:52:31+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:31 volumio volumio5-onboarding[1571]: time=2026-08-29T14:52:31.182+01:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 14:52:31 volumio go-librespot[1689]: time="2026-08-29T14:52:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:31 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 29 14:52:31 volumio volumio[1243]: SPOTIFY: User informations: {"account_id":"5fs0U6djG6","country":"BR","display_name":"Bruno Fialho","email":"bruno.fialho@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31tlxhhvgj5ancrbgiycaqkhkryi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31tlxhhvgj5ancrbgiycaqkhkryi","id":"31tlxhhvgj5ancrbgiycaqkhkryi","images":[],"product":"premium","type":"user","uri":"spotify:user:31tlxhhvgj5ancrbgiycaqkhkryi"} Aug 29 14:52:31 volumio volumio[1243]: info: Spotify Successfully logged in Aug 29 14:52:31 volumio volumio[1243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:52:31 volumio volumio[1243]: info: [1788011551811] CoreMusicLibrary::Adding element Spotify Aug 29 14:52:31 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:52:31 volumio volumio[1243]: Cannot find translation for source YouTube Music Aug 29 14:52:31 volumio volumio[1243]: Cannot find translation for source Spotify Aug 29 14:52:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 14:52:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:34 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:34 volumio go-librespot[1700]: go-librespot daemon starting... Aug 29 14:52:34 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:52:34 volumio go-librespot[1701]: time="2026-08-29T14:52:34+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:34 volumio go-librespot[1701]: time="2026-08-29T14:52:34+01:00" level=debug msg="app state loaded" Aug 29 14:52:34 volumio go-librespot[1701]: time="2026-08-29T14:52:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=info msg="zeroconf server listening on port 35749" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="obtained new client token: AAGTAOvy6RIycZRfQ/WkUBhwOUtXW2C90k5/lWY6xu7iIAFZ4CPXVQ4WnT7EuAqY3vFZjqD2wfMnGy/5Z0q6MoYbnkdw8kK/YDsf1XxSawAr2ewAwTSeSw7aRZnso0kRxaq3Dcc+JOWCqG5xevEh18jXoXmvEr3QBvJ0yRVM2DDOt2YOYII65VR7UKmBI7zV7SCLyhUnR8bUYnbbPOBgClxEdisMy9w0eb3Jy4ArTyx74cc03WBbIqwotA==" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:35 volumio go-librespot[1701]: time="2026-08-29T14:52:35+01:00" level=debug msg="completed challenge" Aug 29 14:52:36 volumio go-librespot[1701]: time="2026-08-29T14:52:36+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:36 volumio go-librespot[1701]: time="2026-08-29T14:52:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:37 volumio volumio[1243]: info: [yt-cast-receiver] DIAL server listening on port 8098 Aug 29 14:52:37 volumio volumio[1243]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 14:52:37 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:52:37 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:37 volumio volumio[1243]: info: CoreStateMachine::pushState Aug 29 14:52:37 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:52:37 volumio volumio[1243]: info: CoreCommandRouter::volumioPushState Aug 29 14:52:38 volumio volumio[1243]: error: [ytcr] VolumeControl failed to obtain volume from Volumio: Aug 29 14:52:38 volumio volumio[1243]: (TypeError) Cannot read properties of undefined (reading 'vol') Aug 29 14:52:38 volumio volumio[1243]: TypeError: Cannot read properties of undefined (reading 'vol') Aug 29 14:52:38 volumio volumio[1243]: at VolumeControl.getVolume (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:56:42) Aug 29 14:52:38 volumio volumio[1243]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 29 14:52:38 volumio volumio[1243]: at async VolumeControl.init (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:28:68) Aug 29 14:52:38 volumio volumio[1243]: at async /data/plugins/music_service/ytcr/dist/index.js:347:13 Aug 29 14:52:38 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:38 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:52:39 volumio volumio[1243]: info: Completed starting Core Plugins Aug 29 14:52:39 volumio volumio[1243]: info: ------------------------------------------- Aug 29 14:52:39 volumio volumio[1243]: info: ----- MyVolumio plugins startup ---- Aug 29 14:52:39 volumio volumio[1243]: info: ------------------------------------------- Aug 29 14:52:39 volumio volumio[1243]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 14:52:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 14:52:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:39 volumio go-librespot[1726]: go-librespot daemon starting... Aug 29 14:52:39 volumio go-librespot[1727]: time="2026-08-29T14:52:39+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:39 volumio go-librespot[1727]: time="2026-08-29T14:52:39+01:00" level=debug msg="app state loaded" Aug 29 14:52:39 volumio go-librespot[1727]: time="2026-08-29T14:52:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=info msg="zeroconf server listening on port 32785" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="obtained new client token: AAFzkIagCXsBx2U3O+HwcHs6fdzB6RKrTt+KMs6qirz0GDTDSrbbSGZK0Z/xB2z/mgtJpn2EibkWM/MgiJ+ieAQf0rPC9tF5+/hOsL94EMjJNG/jsp0ed3DY1qQSOaGToHM5D3kuhWDsQ5uyEvRvBIUNfdzYBNK6G4jwh2um3ygJ2wNnDIQ0IFuX8m3726r2uuFiMKRf8dpTSDdyWK0MCvgzjgvdtuz0VtyJGLZphOBKRQrBvFv/DRJ3ow==" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=debug msg="completed challenge" Aug 29 14:52:40 volumio go-librespot[1727]: time="2026-08-29T14:52:40+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:41 volumio go-librespot[1727]: time="2026-08-29T14:52:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:41 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:41 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:52:43 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:52:43 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:52:44 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 14:52:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 14:52:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:44 volumio go-librespot[1745]: go-librespot daemon starting... Aug 29 14:52:44 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:44 volumio go-librespot[1746]: time="2026-08-29T14:52:44+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:44 volumio go-librespot[1746]: time="2026-08-29T14:52:44+01:00" level=debug msg="app state loaded" Aug 29 14:52:44 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:52:44 volumio go-librespot[1746]: time="2026-08-29T14:52:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=info msg="zeroconf server listening on port 45333" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=debug msg="obtained new client token: AAEYfIO7XVv2UB4rd+0UZzGL8w6JhkyBPEIpSuZQ+jJojxBmQiqsGJvzJ1N/EVXkJGzobi9u8hNMgrnOaHvkHQWu0jwNvcoOY7+Qv9pec7Ukm7cBhcViA4sxgs6Cox0TyxFJ1Nmu7/5FtskXEkcGJm8Ftj40l4vuudhK/nuuDgc3LEpYhofIMYHJdCjl47c0GI/QnhtUD600G3QswIF2F4wqgLHkUAmP5nAhGCVip/G24oTvErYIR+Ez4A==" Aug 29 14:52:45 volumio go-librespot[1746]: time="2026-08-29T14:52:45+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:46 volumio go-librespot[1746]: time="2026-08-29T14:52:46+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:46 volumio go-librespot[1746]: time="2026-08-29T14:52:46+01:00" level=debug msg="completed challenge" Aug 29 14:52:46 volumio go-librespot[1746]: time="2026-08-29T14:52:46+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:46 volumio go-librespot[1746]: time="2026-08-29T14:52:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:47 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:52:48 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 14:52:48 volumio volumio[1243]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 14:52:48 volumio volumio[1243]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 14:52:48 volumio volumio[1243]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 14:52:48 volumio volumio[1243]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 14:52:49 volumio volumio[1243]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 14:52:49 volumio volumio[1243]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 14:52:49 volumio volumio[1243]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 14:52:49 volumio volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 14:52:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 14:52:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:49 volumio go-librespot[1769]: go-librespot daemon starting... Aug 29 14:52:49 volumio go-librespot[1770]: time="2026-08-29T14:52:49+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:49 volumio go-librespot[1770]: time="2026-08-29T14:52:49+01:00" level=debug msg="app state loaded" Aug 29 14:52:49 volumio go-librespot[1770]: time="2026-08-29T14:52:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=info msg="zeroconf server listening on port 41931" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="obtained new client token: AAHrQ9N680R8NcAnGa7O+S8TbVZlEIxRiuNlkEFuiMeBL4gedF3kqig1jBh6f7l2VGZvOgAYyroZ2BUBL1cvKq6/1qPP5c05LFPVdex0lvff3mw3wW4UBPQl/cFY4pFjWyZS5VhdCOSQ7o7tzIvNvmA6Qjgi5s9ZwXw8Kp1+UP6Yn+VSMsW73+RnSxaMHGWWZU+9F+xH8fTpTLwJCWFeJqJSfc+Q3cW0LCduqgqvkhyBuWwZjQAyosmRdQ==" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:50 volumio go-librespot[1770]: time="2026-08-29T14:52:50+01:00" level=debug msg="completed challenge" Aug 29 14:52:51 volumio go-librespot[1770]: time="2026-08-29T14:52:51+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:51 volumio go-librespot[1770]: time="2026-08-29T14:52:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 14:52:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:54 volumio go-librespot[1779]: go-librespot daemon starting... Aug 29 14:52:54 volumio go-librespot[1780]: time="2026-08-29T14:52:54+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:54 volumio go-librespot[1780]: time="2026-08-29T14:52:54+01:00" level=debug msg="app state loaded" Aug 29 14:52:54 volumio go-librespot[1780]: time="2026-08-29T14:52:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=info msg="zeroconf server listening on port 44821" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:52:55 volumio go-librespot[1780]: time="2026-08-29T14:52:55+01:00" level=debug msg="obtained new client token: AAE798t23ycIAeZ4n/TXeMvI24+3qa6cwwd1ZqWvYfNt+ahPkoBkp0CI0Oj1tOr3q1/gZLHBx1GNd7v0sO7Wte1iW4CWbSpnZUcG5ioBgFxSMLfWNJlY36yLLLq9lebheBnhNh3M4fhPkqsvMzgVHt0XllaNFDMin8A0a+K6I4nP2MCvuExQxfIzjCOHkMXqq4bZ6UwHwt7xv3f8Ipu16YLHYRmQQXFlbzQhSXmqUutnF/oxNk9A0+nx4g==" Aug 29 14:52:56 volumio go-librespot[1780]: time="2026-08-29T14:52:56+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:52:56 volumio go-librespot[1780]: time="2026-08-29T14:52:56+01:00" level=debug msg="completed keyexchange" Aug 29 14:52:56 volumio go-librespot[1780]: time="2026-08-29T14:52:56+01:00" level=debug msg="completed challenge" Aug 29 14:52:56 volumio go-librespot[1780]: time="2026-08-29T14:52:56+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:52:56 volumio go-librespot[1780]: time="2026-08-29T14:52:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:52:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:52:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:52:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 14:52:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:52:59 volumio go-librespot[1804]: go-librespot daemon starting... Aug 29 14:52:59 volumio go-librespot[1805]: time="2026-08-29T14:52:59+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:52:59 volumio go-librespot[1805]: time="2026-08-29T14:52:59+01:00" level=debug msg="app state loaded" Aug 29 14:52:59 volumio go-librespot[1805]: time="2026-08-29T14:52:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=info msg="zeroconf server listening on port 41747" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:00 volumio go-librespot[1805]: time="2026-08-29T14:53:00+01:00" level=debug msg="obtained new client token: AAFGUUZ0EhW3metO8jpTsAg20hBKZ9zN8K5b+AHkYq5b0u/jhJjhTpnUEAlLKs8laIHN1NcgRfNEMZ8G8BDCwXVif2fG1wjJpvPLdAv4PxN0CBQnbiflPyfzDAjgnrtWHuds4w/a59q3sH7p22mXayft17yvvUEBRU4V34wVrFEqyUenzGtIQUA1384rweOEymGzBzERKqZnJtQQmJ3EK3Jz/KolMDAz5GxWELldHSxPHdEAZqVVyNU8nw==" Aug 29 14:53:01 volumio go-librespot[1805]: time="2026-08-29T14:53:01+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:01 volumio go-librespot[1805]: time="2026-08-29T14:53:01+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:01 volumio go-librespot[1805]: time="2026-08-29T14:53:01+01:00" level=debug msg="completed challenge" Aug 29 14:53:01 volumio go-librespot[1805]: time="2026-08-29T14:53:01+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:01 volumio go-librespot[1805]: time="2026-08-29T14:53:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 29 14:53:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:04 volumio go-librespot[1815]: go-librespot daemon starting... Aug 29 14:53:04 volumio go-librespot[1816]: time="2026-08-29T14:53:04+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:04 volumio go-librespot[1816]: time="2026-08-29T14:53:04+01:00" level=debug msg="app state loaded" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=info msg="zeroconf server listening on port 34869" Aug 29 14:53:05 volumio go-librespot[1816]: time="2026-08-29T14:53:05+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=debug msg="obtained new client token: AAGeCzhUQx3nDxEoTRZ/VPF58LAP7cpABvQfpoipuk//fqAHmWX24bv+Ni+vWvI84w4w+SXwnJCWxAQssmpSa+UrAh1ZJDX95xYJ7j9JA+/FeFSc3RSLfLO/6EqdfBybZYc5eDQaBJ43gw5MBQNykxpiMprOMwZlftrXtf1iSfrFk6aPZATkPGLiVsB2x00zew0tfhGAkMBFdStu0WHRXyNPdmWp/bDbO4JTmShRKv+wX5S7cwpXGgc=" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=debug msg="completed challenge" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:06 volumio go-librespot[1816]: time="2026-08-29T14:53:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:07 volumio volumio[1243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 14:53:07 volumio volumio[1243]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 14:53:07 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:07 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:07 volumio volumio[1243]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 14:53:08 volumio volumio[1243]: info: MyVolumio login type: Token Aug 29 14:53:09 volumio volumio[1243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 14:53:09 volumio volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 14:53:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 29 14:53:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:09 volumio go-librespot[1825]: go-librespot daemon starting... Aug 29 14:53:09 volumio go-librespot[1827]: time="2026-08-29T14:53:09+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:09 volumio go-librespot[1827]: time="2026-08-29T14:53:09+01:00" level=debug msg="app state loaded" Aug 29 14:53:09 volumio go-librespot[1827]: time="2026-08-29T14:53:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=info msg="zeroconf server listening on port 33137" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=debug msg="obtained new client token: AAF7ETTzwGmDBVlj5RnZ/OkKeBAby80lCDiUCv29kU9egG7mQCQSide8469IAg1S+vDowpDiSFXjt6jdSkgU+ID4BVbuchqiVqol2u6s5P0PN3SgIMXrtXxYByc6Q7UkWv3gct8b0/BUybhFkDGM+/n3jl4i1IjuDhrMbbIUNb4GDEqpMJ1vALt4w7Ett5aQTfVxXhqMrcXKHF+/BA3f95jVmSPnbuNfdk4xCzxZ/igKKg32HyJ+PWH1MQ==" Aug 29 14:53:10 volumio go-librespot[1827]: time="2026-08-29T14:53:10+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:11 volumio go-librespot[1827]: time="2026-08-29T14:53:11+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:11 volumio go-librespot[1827]: time="2026-08-29T14:53:11+01:00" level=debug msg="completed challenge" Aug 29 14:53:11 volumio go-librespot[1827]: time="2026-08-29T14:53:11+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:11 volumio go-librespot[1827]: time="2026-08-29T14:53:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 29 14:53:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:14 volumio go-librespot[1850]: go-librespot daemon starting... Aug 29 14:53:14 volumio go-librespot[1851]: time="2026-08-29T14:53:14+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:14 volumio go-librespot[1851]: time="2026-08-29T14:53:14+01:00" level=debug msg="app state loaded" Aug 29 14:53:14 volumio go-librespot[1851]: time="2026-08-29T14:53:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=info msg="zeroconf server listening on port 35479" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="obtained new client token: AAGsQYdN0uSo4B95ybZK5coZg/7J1ilw8O8OG3J+KxRaN83/G+XWw+0zwjcY+vqazQPy7IQERioscu+QKCUptCH48FvEBw6TYIw01TbEbSPmHcdxnnYe6Pl+ocIh9SAgDAT40DsMhd92OOzchHt6a0CJKhXzQClqiQKKJpNiTqPT/IAs1kFqVKVwJuFVXE1KLLEok9Wz5I6AlUFKb62bt0TEgf1MBBiRhBFHeQK1tnKbmLrrRQwCecEWSg==" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=debug msg="completed challenge" Aug 29 14:53:15 volumio go-librespot[1851]: time="2026-08-29T14:53:15+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:16 volumio go-librespot[1851]: time="2026-08-29T14:53:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:16 volumio upmpdcli[1860]: writing RSA key Aug 29 14:53:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 29 14:53:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:19 volumio go-librespot[1866]: go-librespot daemon starting... Aug 29 14:53:19 volumio go-librespot[1867]: time="2026-08-29T14:53:19+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:19 volumio go-librespot[1867]: time="2026-08-29T14:53:19+01:00" level=debug msg="app state loaded" Aug 29 14:53:19 volumio go-librespot[1867]: time="2026-08-29T14:53:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=info msg="zeroconf server listening on port 38055" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="obtained new client token: AAHeZcK9m0ZYk+Nse7d4jyrkaORqYllmkc8NAUdqzoSHkpmEuZ9XD79Ps3ebu8G86GrO6m1BvBd8dg76n5NfVv1ALBFz71GyiiYWzAgYZwkIqDZhKNfiro6ficUS/50YU9YVMDo9gUKcPmX4JrlQmRsbmCkZJQTdTVs2myauseyESXaB/ekLo610s1J+0zOgyitJsfYdBc2r4gJPSLOO58Utc7XEOQ3JEIYe+9yjDsILdqStR5/abAFWNg==" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=debug msg="completed challenge" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:20 volumio go-librespot[1867]: time="2026-08-29T14:53:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:22 volumio volumio[1243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 14:53:22 volumio volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 14:53:22 volumio volumio[1243]: info: Streaming services startup Aug 29 14:53:22 volumio volumio[1243]: info: Starting Streaming Daemon Aug 29 14:53:23 volumio volumio[1243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 14:53:23 volumio sudo[1890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 14:53:23 volumio sudo[1890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:53:23 volumio sudo[1890]: pam_unix(sudo:session): session closed for user root Aug 29 14:53:23 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:53:23 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 14:53:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 29 14:53:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:24 volumio go-librespot[1896]: go-librespot daemon starting... Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=debug msg="app state loaded" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:24 volumio volumio[1243]: error: Cannot start Volumio Streaming Daemon Aug 29 14:53:24 volumio volumio[1243]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 14:53:24 volumio volumio[1243]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 14:53:24 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=info msg="zeroconf server listening on port 42731" Aug 29 14:53:24 volumio go-librespot[1897]: time="2026-08-29T14:53:24+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:25 volumio volumio[1243]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=debug msg="obtained new client token: AAEJDo25EJuC90MtM02PpjvAQOdnCPeQce9I/bkc57PxcAjlcZnhRwh5FjBArxN66ug7mjS0nKYXZuEAcdH7GfNdm8TNqkg4VVDEbTaZh4fuUMvTglQQlBy5aIqKKhJdIie+x0AGYqG9NtFAAyqxWjqXgLk7OpQh4Z86GdWqBrN3/G6UDfeUHxGlDm98ird8KiQn4lK4llNb2OUVXK/gW26WG7RAmuIN8pXHvo+c2dWxtYzvurlqBGI=" Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=debug msg="completed challenge" Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:25 volumio go-librespot[1897]: time="2026-08-29T14:53:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:25 volumio volumio[1243]: error: MyVolumio Custom Token format not valid, refreshing it Aug 29 14:53:26 volumio volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 29 14:53:26 volumio volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 29 14:53:27 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:53:27 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 14:53:28 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:53:28 volumio volumio[1243]: info: MyVolumio login type: Token Aug 29 14:53:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 29 14:53:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:29 volumio go-librespot[1906]: go-librespot daemon starting... Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=debug msg="app state loaded" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=info msg="zeroconf server listening on port 33045" Aug 29 14:53:29 volumio go-librespot[1907]: time="2026-08-29T14:53:29+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=debug msg="obtained new client token: AAFXegETYlMMoUcE+jkAHzJgz/jbSL2+h5C/95aJ3/5q89gZtHRMFDsEcPYeAb9reJys7kGf5i8Wt31ksq8fvU67+MvXc+TsTYJjphIgByHGm7s58QbAquiutvWEd3t5fmkswlV1S3jy9udb4Yk9+9HRtO1H+QVwYC7F7KF6OG3Jm0AZIduTCCVktFmXy/SBWjNEpFET3Smfaza4Rm6z0fqZoWV3Mf893J3t7i6Q9sW0u0kB2CFM9e4=" Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=debug msg="completed challenge" Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:30 volumio volumio[1243]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 14:53:30 volumio go-librespot[1907]: time="2026-08-29T14:53:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:31 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:53:31 volumio volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:53:31 volumio volumio[1243]: info: MyVolumio token set successfully Aug 29 14:53:31 volumio volumio[1243]: info: MYVOLUMIO: Adding device Aug 29 14:53:31 volumio volumio[1243]: info: MYVOLUMIO: Evaluating Server Aug 29 14:53:33 volumio volumio[1243]: info: MyVolumio status changed Aug 29 14:53:33 volumio volumio[1243]: info: Streaming services startup Aug 29 14:53:33 volumio volumio[1243]: info: Starting Streaming Daemon Aug 29 14:53:33 volumio volumio[1243]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 14:53:33 volumio volumio[1243]: info: Removing audio output: Aug 29 14:53:33 volumio volumio[1243]: info: Stoppping Tunnel 1 Aug 29 14:53:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 29 14:53:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:33 volumio sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 14:53:33 volumio sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:53:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:33 volumio go-librespot[1958]: go-librespot daemon starting... Aug 29 14:53:33 volumio go-librespot[1960]: time="2026-08-29T14:53:33+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:33 volumio go-librespot[1960]: time="2026-08-29T14:53:33+01:00" level=debug msg="app state loaded" Aug 29 14:53:33 volumio sudo[1957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 14:53:33 volumio sudo[1957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:53:33 volumio go-librespot[1960]: time="2026-08-29T14:53:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:33 volumio sudo[1955]: pam_unix(sudo:session): session closed for user root Aug 29 14:53:34 volumio volumio[1243]: info: Setting Geolocation for MyVolumio to eu4 Aug 29 14:53:34 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:34 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 14:53:34 volumio sudo[1957]: pam_unix(sudo:session): session closed for user root Aug 29 14:53:34 volumio volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 29 14:53:34 volumio volumio[1243]: info: Remote SSH Stopped Aug 29 14:53:34 volumio volumio[1243]: error: Cannot start Volumio Streaming Daemon Aug 29 14:53:34 volumio volumio[1243]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 14:53:34 volumio volumio[1243]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="new websocket client" Aug 29 14:53:34 volumio volumio[1243]: info: Connection to go-librespot Websocket established Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=info msg="zeroconf server listening on port 35139" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="obtained new client token: AAHKS3FRWkViv56pIU4CYpdiXtTHXnSu9Xo3WNa6tLDH4e2NeXT32BC/I3FyjyAes5tjhY0zF4PTIcfqIRU0/cpJ3imIEamLc+QNcMdWbkcDTB6XT0oT6p2bbw256hXGRkC5p8w+IEQ0V80hARyl4wAA2n/YpbgJkuGzDr5JYyzLbQCFVgPBcPvjSKoiyqipBAiGGfdwZj6xdE4APNxu/OASe4N1A1WoBdoc6UrXOD8nCOtuJ2/Yj9lvEA==" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:34 volumio volumio[1243]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:34 volumio go-librespot[1960]: time="2026-08-29T14:53:34+01:00" level=debug msg="completed challenge" Aug 29 14:53:35 volumio go-librespot[1960]: time="2026-08-29T14:53:35+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:35 volumio volumio[1243]: info: Updating MyVolumio device info Aug 29 14:53:35 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:35 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:35 volumio volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:53:35 volumio go-librespot[1960]: time="2026-08-29T14:53:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:35 volumio volumio[1243]: info: Connection to go-librespot Websocket closed Aug 29 14:53:35 volumio volumio[1243]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 29 14:53:37 volumio volumio[1243]: info: Getting Spotify volume Aug 29 14:53:37 volumio volumio[1243]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 14:53:37 volumio volumio[1243]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:53:37 volumio volumio[1243]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 14:53:37 volumio volumio[1243]: errno: -111, Aug 29 14:53:37 volumio volumio[1243]: code: 'ECONNREFUSED', Aug 29 14:53:37 volumio volumio[1243]: syscall: 'connect', Aug 29 14:53:37 volumio volumio[1243]: address: '127.0.0.1', Aug 29 14:53:37 volumio volumio[1243]: port: 9879, Aug 29 14:53:37 volumio volumio[1243]: response: undefined Aug 29 14:53:37 volumio volumio[1243]: } Aug 29 14:53:37 volumio volumio[1243]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 14:53:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 29 14:53:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:38 volumio go-librespot[1981]: go-librespot daemon starting... Aug 29 14:53:38 volumio go-librespot[1982]: time="2026-08-29T14:53:38+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:38 volumio go-librespot[1982]: time="2026-08-29T14:53:38+01:00" level=debug msg="app state loaded" Aug 29 14:53:38 volumio go-librespot[1982]: time="2026-08-29T14:53:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=info msg="zeroconf server listening on port 41019" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="obtained new client token: AAHpTQA3jPWLTCyEC3fxVvncyotDGmmGzB6yb7M3jWCyREAh3KHvscDnRnBdImErbi80CcR+WH5733hmJsHB+HyCl0uvHO7Yu1ROJR8MtPjeWE5wleBM2gl2KZqaAhW5pAphZI1/xfkjE3tkeS8WWEe3lmqWkbV9OVKvTD+JhSidNwNQIy1lo4Qy3BbiAvmgmwbWS0nT8PfDnKgHnPeXHI/2vocHmd+qsw3VuO9E39aeYePH7gUPDCuPkw==" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=debug msg="completed challenge" Aug 29 14:53:39 volumio go-librespot[1982]: time="2026-08-29T14:53:39+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:40 volumio go-librespot[1982]: time="2026-08-29T14:53:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 29 14:53:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:43 volumio go-librespot[2006]: go-librespot daemon starting... Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=debug msg="app state loaded" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:43 volumio go-librespot[2007]: time="2026-08-29T14:53:43+01:00" level=info msg="zeroconf server listening on port 42335" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=debug msg="obtained new client token: AAFrQVTAO5a2bNNID5Hj1G2EkfvztmzOb+7ABF7KGK+3R2naBkO8Tx9gUqHPQa8b19GfclgljQkLJoTjxM6TKIU2hMBJZIvjUGjO23Ds9WlkGbWXKoEJNBXsqoGI4nb30CYYsLWMQlvqaECZzyzsSetopWqjDa1kD5ySRJ0xsonZ5bjy4S+YLqZxPSXGIH7JcFQ6yAUip7mA37YGEfHMe56ywwCHnwp7bEZ/f9EzoxGwb3PwnM6IUs0=" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=debug msg="completed challenge" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:44 volumio go-librespot[2007]: time="2026-08-29T14:53:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:53:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 29 14:53:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:53:48 volumio go-librespot[2018]: go-librespot daemon starting... Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=debug msg="app state loaded" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:53:48 volumio sudo[2029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 14:52' Aug 29 14:53:48 volumio sudo[2029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=info msg="zeroconf server listening on port 45671" Aug 29 14:53:48 volumio go-librespot[2019]: time="2026-08-29T14:53:48+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=debug msg="obtained new client token: AAEuOwK8rCRQM2JAhQ44Qq6IVKg7MHoYaDvN51lZXdwXIGKTtyM9Zuad+SLRbP1ydp2aMHVlxdBMT6UO4/N2bALNXr47FjWi+b6ev99VGn5nfmxlPHpOHL3aDSxs0egSsJlwzjCzcAR3Z9HFeLWHwMCE5vQLSHponY+XsTTqnKvJL+HcATQUgf0pBq/HoK+FIiKRqxIadGmDF5UUPkkEERsgT/NccCSZ6s+AAL/d+C+C7lsD1JqXpS0=" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=debug msg="completed keyexchange" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=debug msg="completed challenge" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=info msg="authenticated AP" username="31************************yi" Aug 29 14:53:49 volumio go-librespot[2019]: time="2026-08-29T14:53:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:53:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:53:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"