Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=info msg="zeroconf server listening on port 35521" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:00 volumio volumio[1268]: error: updateQueue error: null Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="obtained new client token: AAESPjKLdEx/Np4gPr3ZTLpLhm9YyxWuXSCy2OTkIwLPxmkZceYInWWMcBmHH9xjj7t8tAeIlCrb1GYKozIdLtlA9k+NNo05USArTuwtsBM9uNtcNGRhsPlqxiKPFqb1+xQPIgEgGHbV2xkphCbKTFryaqZsgJl9ps9C5N06F2yP+BYWsiS1/pn5eZNt0ab/04uf1wCS9KFbrIcwiZwop1Mv5oAgWwDwCBYG/jRoxHoZg7b/8uXBsblL" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=debug msg="completed challenge" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:00 volumio go-librespot[1628]: time="2026-09-01T09:02:00+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:01 volumio volumio[1268]: info: Starting Shairport Sync Sep 01 09:02:01 volumio volumio[1268]: info: Starting Shairport Sync Sep 01 09:02:01 volumio volumio[1268]: info: Starting Shairport Sync Sep 01 09:02:01 volumio sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 09:02:01 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:02 volumio volumio[1268]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Sep 01 09:02:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 09:02:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 09:02:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio systemd[1]: shairport-sync.service: Consumed 2.855s CPU time. Sep 01 09:02:02 volumio sudo[1645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 09:02:02 volumio sudo[1645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:02 volumio sudo[1647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 09:02:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:02 volumio volumio[1268]: info: go-librespot daemon successfully initialized Sep 01 09:02:02 volumio sudo[1647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 09:02:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 09:02:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio sudo[1645]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 09:02:02 volumio volumio[1268]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Sep 01 09:02:02 volumio volumio[1268]: info: Received Get System Info Sep 01 09:02:02 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 09:02:02 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:02 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:02 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:02 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:02 volumio volumio5-onboarding[1619]: time=2026-09-01T09:02:02.898+09:00 level=INFO msg="system info for 871a152d92c97f657f7477d2502c8214" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Sep 01 09:02:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 09:02:02 volumio volumio5-onboarding[1619]: time=2026-09-01T09:02:02.922+09:00 level=INFO msg="bootstrapping state" hasInternet=true Sep 01 09:02:02 volumio sudo[1647]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:03 volumio volumio[1268]: info: Shairport-Sync Started Sep 01 09:02:03 volumio volumio[1268]: Error adding Membership: Error: addMembership EINVAL Sep 01 09:02:03 volumio volumio[1268]: info: Received Get System Info Sep 01 09:02:03 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:03 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:03 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:03 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:03 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:03 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:03 volumio volumio[1268]: info: Shairport-Sync Started Sep 01 09:02:03 volumio volumio[1268]: info: Shairport-Sync Started Sep 01 09:02:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 09:02:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:04 volumio go-librespot[1710]: go-librespot daemon starting... Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=debug msg="app state loaded" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=info msg="zeroconf server listening on port 40089" Sep 01 09:02:04 volumio go-librespot[1711]: time="2026-09-01T09:02:04+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=debug msg="obtained new client token: AAGAd1iVIyjiRnkU/JKWdPXe5nqvG6k6AL+6kU1Qktnour/iDaAVtH3mDuBaUL8DDAQ0BSBcmeIDFqG1dE3ZMcHN23jQzOS2R7JWCZAb9rid3S+gYQrY0YBi2iMOsBOC7W3TtHKg4/qoYt0n8zDtWTHt74PkYe9tIPxjCFhoYXFF4u83FXT4zxvTy9OUxmxmWKImpKmgSl9u94nQG/abuRk66iA1i1kDRG4hFMkASHqNE0ufI7DWBA==" Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=debug msg="completed challenge" Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:05 volumio volumio[1268]: info: Initializing connection to go-librespot Websocket Sep 01 09:02:05 volumio go-librespot[1711]: time="2026-09-01T09:02:05+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 09:02:05 volumio volumio[1268]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 09:02:05 volumio volumio[1268]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 09:02:05 volumio volumio[1268]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 09:02:06 volumio volumio[1268]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 09:02:06 volumio volumio[1268]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 09:02:06 volumio volumio[1268]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 09:02:06 volumio volumio[1268]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 09:02:06 volumio volumio[1268]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 09:02:06 volumio volumio-remote-updater[732]: [2026-09-01 09:02:06] [connect] Successful connection Sep 01 09:02:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 09:02:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:09 volumio go-librespot[1741]: go-librespot daemon starting... Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=debug msg="app state loaded" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=info msg="zeroconf server listening on port 36779" Sep 01 09:02:09 volumio go-librespot[1742]: time="2026-09-01T09:02:09+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=debug msg="obtained new client token: AAFaCDRCA6EEXv9vaT+AN6eL0s3A62OjYMdS0Dh1KOUcX4SLx+sLdXkiz/S2Jt61EWlxYJSclmS1d9iSvD8NF/YrIsAKLU9rMoB63W3l/D5CMBU9IXnYBprpCdgf6Y4K1SeLok459xLhkzFVXQxwqi4dObljvq5BuTO9/c4J4UeLuaFB7+bPZctoFNILi+Hs4Tw8tBW3Izsmhe5unvyldDI1XCrCe0cggpQZjaOQScdTD4tNUbSQfw==" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=debug msg="completed challenge" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:10 volumio go-librespot[1742]: time="2026-09-01T09:02:10+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 09:02:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:13 volumio go-librespot[1751]: go-librespot daemon starting... Sep 01 09:02:13 volumio go-librespot[1752]: time="2026-09-01T09:02:13+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:13 volumio go-librespot[1752]: time="2026-09-01T09:02:13+09:00" level=debug msg="app state loaded" Sep 01 09:02:13 volumio go-librespot[1752]: time="2026-09-01T09:02:13+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=info msg="zeroconf server listening on port 42895" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=debug msg="obtained new client token: AAF1ZOnQDp0Y8sWxJ6GxllcXjZSIuUQrKAYTVGWRKwQisfDxDQw14GgaoyXHVits5AugHayxxIr0yk+XQPf238NNuIpMPX3oGyKwEWeZe0jvMm1J3L6bEX8PZwvf0zYIdMkvEvVPMBRedEhZeH/rgQE+T/KbSm/WBAN/R2AHVpFECtDhvJG6FqHqSFvUUW9AqcXMBKqGdtfndywmQ/ZUb6mDp47wwkcpzWiTc/+tvYIjMr12QXbuCO0N" Sep 01 09:02:14 volumio go-librespot[1752]: time="2026-09-01T09:02:14+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=debug msg="connected to ap-gae2.spotify.com:80" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=debug msg="completed challenge" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:15 volumio go-librespot[1752]: time="2026-09-01T09:02:15+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:17 volumio volumio[1268]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 09:02:17 volumio volumio[1268]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 09:02:17 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:17 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:17 volumio volumio[1268]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 09:02:17 volumio volumio[1268]: info: MyVolumio login type: Token Sep 01 09:02:17 volumio volumio[1268]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 09:02:17 volumio volumio[1268]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 09:02:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 09:02:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:18 volumio go-librespot[1776]: go-librespot daemon starting... Sep 01 09:02:18 volumio go-librespot[1777]: time="2026-09-01T09:02:18+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:18 volumio go-librespot[1777]: time="2026-09-01T09:02:18+09:00" level=debug msg="app state loaded" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=info msg="zeroconf server listening on port 38007" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=debug msg="obtained new client token: AAEKJqPHsFI7U2LC9gcnJV4E7yd/pzk+cvHfoS9L7aNHrzGm01DZDP73pZKAXftSQ2fjRaevqyCpXk8/oKVHbCcZXtz5u+RXDHRhJbMhXhLRdnP4Rq9r2wKlLjHAaeh8ZmUPyjq674ecj9boxxotVucjNXKshJ5r9TDK1BLR5i5n2ZwWutRf1fxu0u09gnTxIJh4HDRtvVJfZLY9VoQ+rhRE1SoK9fceb5bwiHqgmr631BBoxpaHUIZd" Sep 01 09:02:19 volumio go-librespot[1777]: time="2026-09-01T09:02:19+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:20 volumio go-librespot[1777]: time="2026-09-01T09:02:20+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:20 volumio go-librespot[1777]: time="2026-09-01T09:02:20+09:00" level=debug msg="completed challenge" Sep 01 09:02:20 volumio go-librespot[1777]: time="2026-09-01T09:02:20+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:20 volumio go-librespot[1777]: time="2026-09-01T09:02:20+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:21 volumio volumio-remote-updater[732]: [2026-09-01 09:02:21] [connect] Successful connection Sep 01 09:02:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 09:02:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:23 volumio go-librespot[1786]: go-librespot daemon starting... Sep 01 09:02:23 volumio go-librespot[1787]: time="2026-09-01T09:02:23+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:23 volumio go-librespot[1787]: time="2026-09-01T09:02:23+09:00" level=debug msg="app state loaded" Sep 01 09:02:23 volumio go-librespot[1787]: time="2026-09-01T09:02:23+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=info msg="zeroconf server listening on port 38235" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="obtained new client token: AAHsVMdlXmtB5uxsPlUDfChsDxmPVjPmxYqlvMKuq6jOgTtEg3RfmNalnls6w7ALyf7Uc4584UaYGloiU+mI0Y440TnxrAUQj4Sbd1W3KUCHoMUOnuGUYSOKmLSr2Hs6k3fCbU4JUuFCPkhkZPhFqdniZ5z/ZnJ/NUH6PkYa9IExGA40VjRid3nDf5Gtw4kaH5n7xe5bovEPuuyZ5FOd2kvNi5trydhnNMGIFkCAfd5tBCoL6/Seo2DJ" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=debug msg="completed challenge" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:24 volumio go-librespot[1787]: time="2026-09-01T09:02:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 09:02:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:28 volumio go-librespot[1810]: go-librespot daemon starting... Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=debug msg="app state loaded" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=info msg="zeroconf server listening on port 44567" Sep 01 09:02:28 volumio go-librespot[1811]: time="2026-09-01T09:02:28+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=debug msg="obtained new client token: AAGZyaJwSdpMhbAQK4rqOrCmeFLiO/bNf/h56sbUa4ToZ4WLSyH80cmxzlqgpYHclN0HFSEx37w4z07erUS1CliDprtvVnuNSPnM9rzenmnT4WaR8YT/pgBDCLpRKdCugZ+8mcKrT4nL4l6gf4jqrjsTjjKYgi7MbMmTmKforDeiddkBZB0DnbqV3R0HAlxL3TEJ+tJesR/aJN/bXRupQCJ5OMjh6qw4D4YL/c982PdEN036elPSDFON" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=debug msg="completed challenge" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:29 volumio go-librespot[1811]: time="2026-09-01T09:02:29+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:29 volumio volumio[1268]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 09:02:29 volumio volumio[1268]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 09:02:29 volumio volumio[1268]: info: Streaming services startup Sep 01 09:02:29 volumio volumio[1268]: info: Starting Streaming Daemon Sep 01 09:02:30 volumio sudo[1822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 09:02:30 volumio volumio[1268]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 09:02:30 volumio sudo[1822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:30 volumio sudo[1822]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:30 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:30 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:30 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:30 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:30 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:30 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:31 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 09:02:31 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:31 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 09:02:31 volumio volumio[1268]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 09:02:31 volumio volumio[1268]: error: Cannot start Volumio Streaming Daemon Sep 01 09:02:31 volumio volumio[1268]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 09:02:31 volumio volumio[1268]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 09:02:32 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:32 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:32 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:32 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:32 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:32 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 09:02:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:32 volumio volumio5-onboarding[1619]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Sep 01 09:02:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:32 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:32 volumio go-librespot[1831]: go-librespot daemon starting... Sep 01 09:02:32 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Sep 01 09:02:32 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=debug msg="app state loaded" Sep 01 09:02:33 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:33 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:33 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:33 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:33 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:33 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:33 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Sep 01 09:02:33 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Sep 01 09:02:33 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Sep 01 09:02:33 volumio volumio[1268]: error: MyVolumio Custom Token format not valid, refreshing it Sep 01 09:02:33 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:33.387+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=info msg="zeroconf server listening on port 44715" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:33 volumio go-librespot[1832]: time="2026-09-01T09:02:33+09:00" level=debug msg="obtained new client token: AAHw+VijLoAOpwi9ZaX/FLPwRhYN5s308b4uwBKmCDXrfydr4O5+UanB/meayuaSRVjIe3LxAnG3WlEwjIcDLJtUBNW3VDOHn1tWqVnQ4QjMomXXKyrmqoh7UDXHnEC5/aP+DN7Q+9PYXbCojSUnk4prSbvrisQkZG7jUNjqv5H5CyNnNvKXS+4XHynvtP2EeB/tuB/3q1cd38pqhTHbQOFzawAp1qyr71hMgaprPVcYO/DJ/KwRP1dH" Sep 01 09:02:34 volumio go-librespot[1832]: time="2026-09-01T09:02:34+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:34 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:34 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:34 volumio go-librespot[1832]: time="2026-09-01T09:02:34+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:34 volumio go-librespot[1832]: time="2026-09-01T09:02:34+09:00" level=debug msg="completed challenge" Sep 01 09:02:34 volumio go-librespot[1832]: time="2026-09-01T09:02:34+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:34 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:34 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:34 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:34 volumio go-librespot[1832]: time="2026-09-01T09:02:34+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:34 volumio volumio[1268]: info: Initializing connection to go-librespot Websocket Sep 01 09:02:35 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 09:02:35 volumio volumio[1268]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 09:02:36 volumio volumio[1268]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 01 09:02:36 volumio volumio-remote-updater[732]: [2026-09-01 09:02:36] [connect] Successful connection Sep 01 09:02:36 volumio volumio[1268]: SPOTIFY: User informations: {"account_id":"exOdlgDrKu","country":"JP","display_name":"Ryuji.Kawahara","email":"ryuji.kawahara0128@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31chfcoryu7yopcrv5fqmcq2outa"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31chfcoryu7yopcrv5fqmcq2outa","id":"31chfcoryu7yopcrv5fqmcq2outa","images":[],"product":"free","type":"user","uri":"spotify:user:31chfcoryu7yopcrv5fqmcq2outa"} Sep 01 09:02:36 volumio volumio[1268]: info: Spotify Successfully logged in Sep 01 09:02:36 volumio volumio[1268]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 09:02:36 volumio volumio[1268]: info: [1788220956453] CoreMusicLibrary::Adding element Spotify Sep 01 09:02:36 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 09:02:36 volumio volumio[1268]: Cannot find translation for source Spotify Sep 01 09:02:37 volumio volumio[1268]: 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 Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 09:02:37 volumio volumio[1268]: 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 Sep 01 09:02:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 09:02:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:37 volumio volumio[1268]: info: Received Get System Info Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:37 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:37 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:37 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:37.570+09:00 level=INFO msg="system info for 871a152d92c97f657f7477d2502c8214" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Sep 01 09:02:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:37 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:37.585+09:00 level=INFO msg="bootstrapping state" hasInternet=true Sep 01 09:02:37 volumio go-librespot[1851]: go-librespot daemon starting... Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:37 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:37 volumio go-librespot[1852]: time="2026-09-01T09:02:37+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:37 volumio go-librespot[1852]: time="2026-09-01T09:02:37+09:00" level=debug msg="app state loaded" Sep 01 09:02:37 volumio go-librespot[1852]: time="2026-09-01T09:02:37+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:37 volumio volumio[1268]: info: Received Get System Info Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:37 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:37 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:37 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:37 volumio volumio-remote-updater[732]: [2026-09-01 09:02:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788220956 101 Sep 01 09:02:38 volumio volumio[1268]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Sep 01 09:02:38 volumio volumio-remote-updater[732]: Test mode disabled Sep 01 09:02:38 volumio volumio-remote-updater[732]: Alpha mode disabled Sep 01 09:02:38 volumio volumio-remote-updater[732]: Alpha legacy test mode disabled Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=info msg="zeroconf server listening on port 44289" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="obtained new client token: AAEkRlTzhV7QqpVd1KG07L/ozoZYuWLAoGmSh310Z+PDRaWvjsBZG6DCPv3YWr8JFyIbTcPtqxh4AnixgsIm25jpBOo4VSJepPklIM8M0r/eaRXUerRpMGI9olnPl8YxMN2Fht9gJqryy5u4yMczy9LlcTw7ntleXLNBW1ifEXgos3tjiKB7m+hV1qyrhh2Sm6NvzN1FEo/oM0divuZUFGYcE8p37hlUCb6IMOcVdMBY9DA6NErtymFE" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=debug msg="completed challenge" Sep 01 09:02:38 volumio go-librespot[1852]: time="2026-09-01T09:02:38+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:39 volumio go-librespot[1852]: time="2026-09-01T09:02:39+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:39 volumio volumio[1268]: info: Initializing connection to go-librespot Websocket Sep 01 09:02:40 volumio volumio[1268]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 09:02:40 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 09:02:40 volumio volumio[1268]: info: MyVolumio login type: Token Sep 01 09:02:40 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 09:02:40 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:40.749+09: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" Sep 01 09:02:40 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:40.752+09: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" Sep 01 09:02:40 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:40.752+09: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" Sep 01 09:02:40 volumio volumio[1268]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 09:02:40 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 09:02:41 volumio volumio[1268]: info: Received Get System Info Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 09:02:41 volumio volumio[1268]: info: Discovery: Getting this device information Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:41 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 09:02:41 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:41.905+09:00 level=INFO msg="enabling local network discovery" Sep 01 09:02:41 volumio volumio[1268]: info: CoreCommandRouter::volumioGetState Sep 01 09:02:41 volumio volumio[1268]: info: CorePlayQueue::getTrack 0 Sep 01 09:02:41 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:41.963+09:00 level=INFO msg="enabling BLE discovery" Sep 01 09:02:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 01 09:02:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:42 volumio go-librespot[1879]: go-librespot daemon starting... Sep 01 09:02:42 volumio go-librespot[1880]: time="2026-09-01T09:02:42+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:42 volumio go-librespot[1880]: time="2026-09-01T09:02:42+09:00" level=debug msg="app state loaded" Sep 01 09:02:42 volumio go-librespot[1880]: time="2026-09-01T09:02:42+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:43 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:43.020+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=info msg="zeroconf server listening on port 35175" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="obtained new client token: AAEezeO3jsEckWQ8niKDvP3adI33uTdK6Q6MrVQVcrnJ8t2mEq+JJMcbw9yRHzanYR1B3D/dOQunojcBg5RQqRyXnR7AWf370I+1Bf1jxowX8rMKfTIVA3CT2n4N2biY7TrPbBQsDJwjQ7j+lsjzIA/yO+pnTGUFrHQ14gAJaQzL7GXkrNbsutZisUo1txnX5Wf+rOsb58K/qAVXAb6MAu1jvgAhF8SyjgSWrk9lj2CV+KYRCTuP3dqj" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=debug msg="completed challenge" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:43 volumio go-librespot[1880]: time="2026-09-01T09:02:43+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:44 volumio volumio[1268]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 09:02:44 volumio volumio[1268]: info: Initializing connection to go-librespot Websocket Sep 01 09:02:44 volumio volumio[1268]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 09:02:44 volumio volumio[1268]: info: MyVolumio token set successfully Sep 01 09:02:44 volumio volumio[1268]: info: MYVOLUMIO: Adding device Sep 01 09:02:44 volumio volumio[1268]: info: MYVOLUMIO: Evaluating Server Sep 01 09:02:46 volumio volumio[1268]: info: MyVolumio status changed Sep 01 09:02:46 volumio volumio[1268]: info: Streaming services startup Sep 01 09:02:46 volumio volumio[1268]: info: Starting Streaming Daemon Sep 01 09:02:46 volumio volumio[1268]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 09:02:46 volumio volumio[1268]: info: Removing audio output: Sep 01 09:02:46 volumio volumio[1268]: info: Stoppping Tunnel 1 Sep 01 09:02:46 volumio sudo[1911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 09:02:46 volumio sudo[1911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 01 09:02:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:47 volumio sudo[1914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 09:02:47 volumio sudo[1914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:02:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:47 volumio sudo[1911]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:47 volumio go-librespot[1915]: go-librespot daemon starting... Sep 01 09:02:47 volumio volumio[1268]: error: Cannot start Volumio Streaming Daemon Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=debug msg="app state loaded" Sep 01 09:02:47 volumio volumio[1268]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 09:02:47 volumio volumio[1268]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 09:02:47 volumio volumio[1268]: info: Initializing connection to go-librespot Websocket Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=debug msg="new websocket client" Sep 01 09:02:47 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. Sep 01 09:02:47 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. Sep 01 09:02:47 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. Sep 01 09:02:47 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. Sep 01 09:02:47 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. Sep 01 09:02:47 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. Sep 01 09:02:47 volumio sudo[1914]: pam_unix(sudo:session): session closed for user root Sep 01 09:02:47 volumio volumio[1268]: info: Connection to go-librespot Websocket established Sep 01 09:02:47 volumio volumio[1268]: info: Remote SSH Stopped Sep 01 09:02:47 volumio volumio[1268]: info: Setting Geolocation for MyVolumio to as1 Sep 01 09:02:47 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:47 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:47 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=info msg="zeroconf server listening on port 46669" Sep 01 09:02:47 volumio go-librespot[1917]: time="2026-09-01T09:02:47+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:48 volumio volumio[1268]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=debug msg="obtained new client token: AAEVXqgdEkFWCKC9AiN7lqYl72wcOPqzwaYJjXy/4pAjkcQdvcH4WW4eTWnZk5WbEX5FLMsNZINHtl2NeBHf7GGP5+ocbG4CFn3UWs9xV19hJcXnN8pDGix7AQcrbs8UaYxQNIHsXy8m8++xy8AAsZ9m0BYyFQ30vymamkyGe9KC9C3XbZGxAM25PzOKWar8KQtH/jicjg3XuFinh1vSRxaIYlxdOOnXmKHQjwmo0zQ63MaLKiCTbQ==" Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=debug msg="completed challenge" Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:48 volumio go-librespot[1917]: time="2026-09-01T09:02:48+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:48 volumio volumio[1268]: info: Connection to go-librespot Websocket closed Sep 01 09:02:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:48 volumio volumio[1268]: info: Updating MyVolumio device info Sep 01 09:02:48 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:48 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:48 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:49 volumio volumio[1268]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 09:02:50 volumio volumio[1268]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 01 09:02:50 volumio volumio[1268]: info: Completed starting MyVolumio Plugin Sep 01 09:02:50 volumio volumio[1268]: [Metrics] CommandRouter: 103s 799.31ms Sep 01 09:02:50 volumio volumio[1268]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 09:02:50 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 09:02:50 volumio volumio[1268]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 09:02:50 volumio volumio[1268]: info: CoreCommandRouter::Close All Modals sent Sep 01 09:02:50 volumio volumio[1268]: info: CoreCommandRouter::Close All Modals sent Sep 01 09:02:50 volumio volumio[1268]: info: Getting Spotify volume Sep 01 09:02:50 volumio volumio[1268]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 09:02:50 volumio volumio[1268]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 09:02:50 volumio volumio[1268]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 09:02:50 volumio volumio[1268]: errno: -111, Sep 01 09:02:50 volumio volumio[1268]: code: 'ECONNREFUSED', Sep 01 09:02:50 volumio volumio[1268]: syscall: 'connect', Sep 01 09:02:50 volumio volumio[1268]: address: '127.0.0.1', Sep 01 09:02:50 volumio volumio[1268]: port: 9879, Sep 01 09:02:50 volumio volumio[1268]: response: undefined Sep 01 09:02:50 volumio volumio[1268]: } Sep 01 09:02:50 volumio volumio[1268]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.146+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.133:53241 Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.216+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.133:53243 Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.241+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.133:53241 @ 0x1c007b0" latency=13.499418ms timeout=20s Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.242+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.133:53241 @ 0x1c007b0" Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.242+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.133:53241 @ 0x1c007b0" latency=13.763835ms platform=PLATFORM_IOS version=6.260807.0 Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.298+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.133:53241,192.168.0.133:53243 @ 0x1c007b0" latency=10.669845ms timeout=20s Sep 01 09:02:51 volumio volumio5-onboarding[1840]: time=2026-09-01T09:02:51.299+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.133:53241,192.168.0.133:53243 @ 0x1c007b0" Sep 01 09:02:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 01 09:02:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:52 volumio go-librespot[1953]: go-librespot daemon starting... Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=debug msg="app state loaded" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=info msg="zeroconf server listening on port 43685" Sep 01 09:02:52 volumio go-librespot[1954]: time="2026-09-01T09:02:52+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=debug msg="obtained new client token: AAHkbqifLcUG2dP0tth2tYI6VA9xVRonNnceVKUdDM1toCloNIIJCmKbAaw5ltveLA5H5KS2G3GYMTVR+aEXuLx20LcSBhoGLCRMQ446732Ego/I3/5VQvjYonOhw+FNP9q/WLwA87udIqo4QQy4PcCBDC4U6HPxEn5Ze8I9PsP3uKVBLrdXn3gX2syNInUgzIrZDYzWWL2LQQDSIBm1y1hYD69uhmJJeR2bYU1oLldYyotMZC2KOw==" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=debug msg="completed challenge" Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:53 volumio bluealsa[1008]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_4D_05_BB_FB_A2_62, ...) Sep 01 09:02:53 volumio go-librespot[1954]: time="2026-09-01T09:02:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:02:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 09:02:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:02:57 volumio go-librespot[1965]: go-librespot daemon starting... Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=debug msg="app state loaded" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:02:57 volumio go-librespot[1966]: time="2026-09-01T09:02:57+09:00" level=info msg="zeroconf server listening on port 43677" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=debug msg="obtained new client token: AAGQc8CZlEvXctZyQEU3gtbGUMMCloszydJc18AOqS42BK0mNxbxwF+TEiN3DwIpj07YgY6B4MCdNLBKG+EM8+5BZl0rfD7IhVRsQd4MHKP1NL4X3UoOaY5eWFZqdjEffxtOLrxzCSiIOlddKyUILGI9cx246E0nfQymkZ1AqD5yJ03k6WAAGVMyDGsEz9xqiF+BAjiuPdKYMvaZ5nR9cmYc6BGIdUJBHiPvPqSQGXtnXBYok3yicg==" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=debug msg="completed keyexchange" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=debug msg="completed challenge" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=info msg="authenticated AP" username="31************************ta" Sep 01 09:02:58 volumio go-librespot[1966]: time="2026-09-01T09:02:58+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 09:02:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 09:02:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 09:03:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 01 09:03:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:03:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 09:03:02 volumio go-librespot[1989]: go-librespot daemon starting... Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=debug msg="app state loaded" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 09:03:02 volumio sudo[2001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 09:02' Sep 01 09:03:02 volumio sudo[2001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=info msg="zeroconf server listening on port 33373" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 09:03:02 volumio go-librespot[1990]: time="2026-09-01T09:03:02+09:00" level=debug msg="obtained new client token: AAGRROw9ObjL5TeqOgkUdd2gIIjbmM/WSwNjfR5Upk+LAePSLaLZgYkRuCg0mhlLR6zSZTPDZLh9Fl6UC3uNn85mLNowczQWxVverHOre7duZbLncuZRlNCRQp4KpRRknsqZYC9niJDa7WJuvUcm0LHiiW/rxTJrPvLEtiFt5DwWjA3kNtI3n+At6oMAowyWFz9wttnNZQE/Ak6dUHK+b3InpkiIe7Wn0q1XdjNv7T/WBkh7XvSH1au1" Sep 01 09:03:03 volumio go-librespot[1990]: time="2026-09-01T09:03:03+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"