Aug 29 10:47:00 deskplayer go-librespot[2140]: time="2026-08-29T10:47:00+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:00 deskplayer go-librespot[2140]: time="2026-08-29T10:47:00+02:00" level=debug msg="app state loaded"
Aug 29 10:47:00 deskplayer go-librespot[2140]: time="2026-08-29T10:47:00+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:00 deskplayer pirate_port[1714]: [2026-08-29T08:47:00.941Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=info msg="zeroconf server listening on port 41309"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="obtained new client token: AAGqsnPDMwXZ2PGMYGCueEVTg3g0LzoArVsPXlk5ecYDvgHlG8NVActxiHNB4QawefqXx6KEHkNxZCjk61kLZJkGYQSKTSdT/JcBP5bZsHtsgbiYgVLQ/0GaUaO80AU9n52Yz6qkl+qO1y7E9BZqyEE8FepXZzp9a5qz2LnYr+wcXY48S/7qATRtd8rl+FXSa5cTdnT0zbCVR3x2+iIzO7UtE75Dy1mG6tqJVfkCCkwiUEWyt6z1JA=="
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=debug msg="completed challenge"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:01 deskplayer go-librespot[2140]: time="2026-08-29T10:47:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:01 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:01 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:04 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Aug 29 10:47:04 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:04 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:04 deskplayer go-librespot[2163]: go-librespot daemon starting...
Aug 29 10:47:04 deskplayer go-librespot[2164]: time="2026-08-29T10:47:04+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:04 deskplayer go-librespot[2164]: time="2026-08-29T10:47:04+02:00" level=debug msg="app state loaded"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=info msg="zeroconf server listening on port 45233"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="obtained new client token: AAFc0sPeEwJX+qsZ5klcnCcU+PIM3iJpciHXbDd2+ZW+hQYlbvCcb84jX1HJ4P+SjmJeqjkovbEE66DmcURQAUPl18T1PVArGubBeR0QvknDyki5zSIMCJto/wG/VoPtgX2NYkht9TDbZ+Nd5R8TRe8vU67hLC6RTyYwBBZde3jXzflOOcPt6NjloxMXYgiGU0lhUskB6mC+lyv8KyQPRvOiKic47EEtTNLupoqKAf4/m6HNQUO7+IN9"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=debug msg="completed challenge"
Aug 29 10:47:05 deskplayer go-librespot[2164]: time="2026-08-29T10:47:05+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:06 deskplayer go-librespot[2164]: time="2026-08-29T10:47:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:06 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:06 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:08 deskplayer pirate_port[1714]: [2026-08-29T08:47:08.962Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:09 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Aug 29 10:47:09 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:09 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:09 deskplayer go-librespot[2174]: go-librespot daemon starting...
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=debug msg="app state loaded"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:09 deskplayer go-librespot[2175]: time="2026-08-29T10:47:09+02:00" level=info msg="zeroconf server listening on port 43165"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=debug msg="obtained new client token: AAEJE+WdC8GkkGn81m+TgrfXK5Qme9um3tJtbL9zqbuUI0sVwIwQxyMgSN9Ne3TD2Rw7In45OxJQvhj+lAkyIw19eHSCJUPHkgNZ1Sb9nkQ+lUFfq5TF+34UoD00DbBJwMsmNV/0YxLbfDXY63Ajel2jD9gNPwTV/s1LTjSJ4GDQYf0GfT1NqZjLqqsKJliynUVohw6quiI2eIRJS5eDqXOhzapA+DSkCA373Xt6c2Qn+usZdl3udg=="
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=debug msg="completed challenge"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:10 deskplayer go-librespot[2175]: time="2026-08-29T10:47:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:10 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:10 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:13 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Aug 29 10:47:13 deskplayer systemd[1]: Starting fstrim.service - Discard unused blocks on filesystems from /etc/fstab...
Aug 29 10:47:13 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:13 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:13 deskplayer go-librespot[2199]: go-librespot daemon starting...
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="app state loaded"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:14 deskplayer fstrim[2198]: /boot: 271.3 MiB (284446720 bytes) trimmed on /dev/mmcblk0p1
Aug 29 10:47:14 deskplayer systemd[1]: fstrim.service: Deactivated successfully.
Aug 29 10:47:14 deskplayer systemd[1]: Finished fstrim.service - Discard unused blocks on filesystems from /etc/fstab.
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=info msg="zeroconf server listening on port 45845"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="obtained new client token: AAE+dldwE9XcNZIAEdERmkA2SIW69bO6zBUGpJzY3LU1/2tZTlXQn8hPFLASpJbwnriMgMZfnMYWKImngvX989KSUK/GZdZO6swHUF96plJMT9wTj0WbpnhhchDErlyLAL7Vl8cOzA6kLXQM6ki5LP0Pzk+28jw6+hokBdtm5Xp2Aepr6cAms3TeOsopcq1J61eXucrhIgkmFLKnKuK77u9Di1Ppv5uARykJ7oQMh5+806qyvZHInFBo"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:14 deskplayer go-librespot[2200]: time="2026-08-29T10:47:14+02:00" level=debug msg="completed challenge"
Aug 29 10:47:15 deskplayer go-librespot[2200]: time="2026-08-29T10:47:15+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:15 deskplayer go-librespot[2200]: time="2026-08-29T10:47:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:15 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:15 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:17 deskplayer pirate_port[1714]: [2026-08-29T08:47:17.000Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:18 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Aug 29 10:47:18 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:18 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:18 deskplayer go-librespot[2216]: go-librespot daemon starting...
Aug 29 10:47:18 deskplayer go-librespot[2217]: time="2026-08-29T10:47:18+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:18 deskplayer go-librespot[2217]: time="2026-08-29T10:47:18+02:00" level=debug msg="app state loaded"
Aug 29 10:47:18 deskplayer go-librespot[2217]: time="2026-08-29T10:47:18+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:18 deskplayer volumio[1430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Aug 29 10:47:18 deskplayer volumio[1430]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Aug 29 10:47:18 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:18 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:18 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:18 deskplayer volumio[1430]: info: Starting MyVolumio Remote Streaming Endpoints
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=info msg="zeroconf server listening on port 39895"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:19 deskplayer volumio[1430]: info: MyVolumio login type: Token
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="obtained new client token: AAGF1ACJW/v2F8ILAUj5AkpcBQClpFeNKzq4I+Wq/4QcAYOIlJ3sJjaXzs0t64p1B4ML+a7al2R5AVVdHoTgYwT5ZdyioA5I8s38qK0ztt/745gJQzUF3d35cwByWAFpCA6RsiNjEYMUVnI9IsF6Jnu+Uda3jqHjmn61sNirGET3Wp5ShdktgjmOqHuMgCxmMd5jjYW2D+iQ2PogPKT4cbQNrz7ZKW0P+iPjpG5/p+m9MVxU885zie43"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=debug msg="completed challenge"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:19 deskplayer go-librespot[2217]: time="2026-08-29T10:47:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:19 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:19 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:19 deskplayer volumio[1430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Aug 29 10:47:19 deskplayer volumio[1430]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Aug 29 10:47:23 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Aug 29 10:47:23 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:23 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:23 deskplayer go-librespot[2240]: go-librespot daemon starting...
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=debug msg="app state loaded"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=info msg="zeroconf server listening on port 41301"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:23 deskplayer go-librespot[2241]: time="2026-08-29T10:47:23+02:00" level=debug msg="obtained new client token: AAHSudA7WYMPoK8A58uby2/MD836qmoRmGDeBfONbY9BiJsAIpqaXewYbgJaigfHYVTrR8lH9sKxlvkjLGAvLNmu7GALFGB++Jf1R+1K6sXEWzJDQAIftAG/M/idnmTfQhglnTIXokqtxtG9ZKXXjZ0O7MqyL9mhGhOwAEn1w4VHXr6H+TxVzB/pTDyNyevCTxhT3kCzWN/2iNquVhqYbyaOj4gOcAMx91sKlT7Dr6Wn4WB00ePT9UDE"
Aug 29 10:47:24 deskplayer go-librespot[2241]: time="2026-08-29T10:47:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:24 deskplayer go-librespot[2241]: time="2026-08-29T10:47:24+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:24 deskplayer go-librespot[2241]: time="2026-08-29T10:47:24+02:00" level=debug msg="completed challenge"
Aug 29 10:47:24 deskplayer go-librespot[2241]: time="2026-08-29T10:47:24+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:24 deskplayer go-librespot[2241]: time="2026-08-29T10:47:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:24 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:24 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:25 deskplayer pirate_port[1714]: [2026-08-29T08:47:25.030Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:27 deskplayer volumio5-onboarding[2095]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded
Aug 29 10:47:27 deskplayer systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:27 deskplayer systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Aug 29 10:47:27 deskplayer systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3.
Aug 29 10:47:27 deskplayer systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 29 10:47:27 deskplayer systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 29 10:47:27 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Aug 29 10:47:27 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:27 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:27 deskplayer go-librespot[2251]: go-librespot daemon starting...
Aug 29 10:47:27 deskplayer go-librespot[2252]: time="2026-08-29T10:47:27+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:27 deskplayer go-librespot[2252]: time="2026-08-29T10:47:27+02:00" level=debug msg="app state loaded"
Aug 29 10:47:27 deskplayer volumio5-onboarding[2250]: time=2026-08-29T10:47:27.564+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Aug 29 10:47:27 deskplayer go-librespot[2252]: time="2026-08-29T10:47:27+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=info msg="zeroconf server listening on port 43825"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="obtained new client token: AAHRS0uzfesOV7uTx1CDeN9PlK5KWn6cRAMiqELYseE9BU9n9tlI4ow2EPOVkgYz4+eXeGsKxgPm+QMht14ypBdbea4ryJoLEmRUivTCb1zn0MuWj69k360FK//dwFxKHaEnvlq39PDd0CscauVL5BYPv82If1NWgbXEcmx85rIAuC9lTuZOEKFx1+lfweTj1qxQf3Lidl8jlOe3zA8fkIMIjhHut1R5sM9nNTU4VPuvDncEtuVUHw=="
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=debug msg="completed challenge"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:28 deskplayer go-librespot[2252]: time="2026-08-29T10:47:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:28 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:28 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:29 deskplayer CRON[610]: pam_unix(cron:session): session closed for user volumio
Aug 29 10:47:31 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Aug 29 10:47:31 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:31 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:31 deskplayer go-librespot[2271]: go-librespot daemon starting...
Aug 29 10:47:31 deskplayer go-librespot[2272]: time="2026-08-29T10:47:31+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:31 deskplayer go-librespot[2272]: time="2026-08-29T10:47:31+02:00" level=debug msg="app state loaded"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=info msg="zeroconf server listening on port 37705"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="obtained new client token: AAHfetFQwVrgX4fnBwFGjwnVIjNHvVEPEmfYV/m9iIYC1/WxygnCzG7R7ZDLoj+KadVYskYiNJuVp+WKOOmT2WwlcbE8cC9bO3yX1+M0LfhPjY//7rGS7WBTjHRxVMAG3TUb0TzaPsYuCupzhn/OosIjPnbBpieGkK6f0TQ1YQvQpfBceSCNMzkGRHJkMfkZxk2KBE12jWdlIhH6ou7tcvUSHFUxScBqdqUw7bAdwNlwonkoepxT0XVc"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=debug msg="completed challenge"
Aug 29 10:47:32 deskplayer go-librespot[2272]: time="2026-08-29T10:47:32+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:33 deskplayer pirate_port[1714]: [2026-08-29T08:47:33.058Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:33 deskplayer go-librespot[2272]: time="2026-08-29T10:47:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:33 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:33 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:36 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Aug 29 10:47:36 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:36 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:36 deskplayer go-librespot[2296]: go-librespot daemon starting...
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=debug msg="app state loaded"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=info msg="zeroconf server listening on port 40433"
Aug 29 10:47:36 deskplayer go-librespot[2297]: time="2026-08-29T10:47:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:36 deskplayer volumio[1430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Aug 29 10:47:36 deskplayer volumio[1430]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Aug 29 10:47:36 deskplayer volumio[1430]: info: Streaming services startup
Aug 29 10:47:36 deskplayer volumio[1430]: info: Starting Streaming Daemon
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=debug msg="obtained new client token: AAHJDA5nkW2GB8W/8vpVeBlk7he4xoR2iSIEy7QSIQoBT0pdo2S3FwAf5PY4ZB3b5WZNjSkOFrry65fLX55Pz0nd4EfEr6l3B0qKuSKj7LsHX0orlqNyK0tTPck9RjL+z0/85CtIHPVAb64U72NJbEKwb+oNcOXby9qBQy+8Ns5IFdQh66L/1Ar9oceMNhCWyvAf6LfQaoShF8/dqSd4oy3OApJn6OwbEVmV/Ep6MqZWy2aLhzKWLw=="
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:37 deskplayer volumio[1430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=debug msg="completed challenge"
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:37 deskplayer sudo[2307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Aug 29 10:47:37 deskplayer sudo[2307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:47:37 deskplayer go-librespot[2297]: time="2026-08-29T10:47:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:37 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:37 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:37 deskplayer volumio5-onboarding[2250]: 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:53152->127.0.0.1:3000: i/o timeout
Aug 29 10:47:37 deskplayer systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:37 deskplayer systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Aug 29 10:47:37 deskplayer systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4.
Aug 29 10:47:37 deskplayer systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 29 10:47:37 deskplayer systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 29 10:47:37 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:37.904+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Aug 29 10:47:37 deskplayer sudo[2307]: pam_unix(sudo:session): session closed for user root
Aug 29 10:47:38 deskplayer volumio[1430]: info: AutoStart - Check #5/60 - VOLUMIO_SYSTEM_STATUS = starting
Aug 29 10:47:38 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:47:38 deskplayer volumio[1430]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory
Aug 29 10:47:38 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:38 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 29 10:47:38 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:38 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Aug 29 10:47:39 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 29 10:47:39 deskplayer volumio-remote-updater[600]: Test mode disabled
Aug 29 10:47:39 deskplayer volumio-remote-updater[600]: Alpha mode disabled
Aug 29 10:47:39 deskplayer volumio-remote-updater[600]: Alpha legacy test mode disabled
Aug 29 10:47:39 deskplayer volumio[1430]: error: Cannot start Volumio Streaming Daemon
Aug 29 10:47:39 deskplayer volumio[1430]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Aug 29 10:47:39 deskplayer volumio[1430]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetBrowseSources
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 29 10:47:40 deskplayer volumio[1430]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 29 10:47:40 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 29 10:47:40 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11
Aug 29 10:47:40 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:47:40 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Aug 29 10:47:40 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:40 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:40 deskplayer go-librespot[2325]: go-librespot daemon starting...
Aug 29 10:47:40 deskplayer go-librespot[2326]: time="2026-08-29T10:47:40+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:40 deskplayer go-librespot[2326]: time="2026-08-29T10:47:40+02:00" level=debug msg="app state loaded"
Aug 29 10:47:40 deskplayer go-librespot[2326]: time="2026-08-29T10:47:40+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:41 deskplayer pirate_port[1714]: [2026-08-29T08:47:41.085Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=info msg="zeroconf server listening on port 41449"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="obtained new client token: AAGDYLr7yDqyQiBKTtA41bxJcu1ge5kNMAC0KZSa9F7y3XIEdz7gtzoXZWizdTzKDHfS/+WZzS8B6Rz0lUDg3uAdBqXW/ZACC3kX0mPSiR7BYt0XvyEROrpaQ7QjggYpP5SK4e49oOlqUhuSZyiY/j+jFZcZ6gyNDjkGH2JHHd+zcwAn/kdN/KbEZfqJ1M32xiHXo7RA8URr80lxiU5L5Q5gKlhJbVvnQz0P+WcvOtcZL+y7UMX+Bmm/"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=debug msg="completed challenge"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:41 deskplayer go-librespot[2326]: time="2026-08-29T10:47:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:41 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:41 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:42 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12
Aug 29 10:47:42 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13
Aug 29 10:47:43 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14
Aug 29 10:47:43 deskplayer volumio[1430]: error: MyVolumio Custom Token format not valid, refreshing it
Aug 29 10:47:43 deskplayer sudo[2353]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 29 10:47:43 deskplayer sudo[2353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:47:43 deskplayer sudo[2351]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 29 10:47:43 deskplayer sudo[2353]: pam_unix(sudo:session): session closed for user root
Aug 29 10:47:43 deskplayer volumio[1430]: info: AutoStart - Check #6/60 - VOLUMIO_SYSTEM_STATUS = starting
Aug 29 10:47:43 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:47:43 deskplayer sudo[2351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:47:43 deskplayer sudo[2351]: pam_unix(sudo:session): session closed for user root
Aug 29 10:47:44 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15
Aug 29 10:47:44 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16
Aug 29 10:47:44 deskplayer volumio[1430]: SPOTIFY: User informations: {"account_id":"w8s8Q2MOh8","country":"AT","display_name":"stekst","email":"herbert.geier@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/stekst"},"followers":{"href":null,"total":6},"href":"https://api.spotify.com/v1/users/stekst","id":"stekst","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464925005_8906164299408226_6672725636641885714_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=107&ccb=1-7&_nc_sid=08baa4&_nc_ohc=96nGI65eMcAQ7kNvwENnyZo&_nc_oc=AdoldEbb-ua5P-D6nxgKiLChrTUlP6ILm-lEgVWWdFLjHcDzrYE-nVxL2O5bEJrbiD4nf2dy2iiz-ZFn0Vti6dWx&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=KCaRNhDEv1glM_ildpa08Q&_nc_tpa=Q5bMBQKIchRIgJMJWGNyK7FtNsfI7ph3yOzbyRXnn1AX4c45RQpDuuDBVfTRVO0kx-DsNf4rnVXQ&oh=00_AQLOjPCFOXIwOYj1gmAiWI3Gf70YGsDn9avAIMjnWaAwiQ&oe=6A98552B","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464925005_8906164299408226_6672725636641885714_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=107&ccb=1-7&_nc_sid=28885b&_nc_ohc=96nGI65eMcAQ7kNvwENnyZo&_nc_oc=AdoldEbb-ua5P-D6nxgKiLChrTUlP6ILm-lEgVWWdFLjHcDzrYE-nVxL2O5bEJrbiD4nf2dy2iiz-ZFn0Vti6dWx&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=KCaRNhDEv1glM_ildpa08Q&_nc_tpa=Q5bMBQL6qk9gu451O7W253LfRCsfBhGt-YaQswl0ee3SBsLRhPECgzghpeILKByqIwoevGZaCL_Y&oh=00_AQL_qTx_tHYJQse2WKpWlYTEL8j6ieCvhtxHjNHC-znbcw&oe=6A98552B","width":64}],"product":"premium","type":"user","uri":"spotify:user:stekst"}
Aug 29 10:47:44 deskplayer volumio[1430]: info: Spotify Successfully logged in
Aug 29 10:47:44 deskplayer volumio[1430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 29 10:47:44 deskplayer volumio[1430]: info: [1787993264878] CoreMusicLibrary::Adding element Spotify
Aug 29 10:47:44 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 29 10:47:44 deskplayer volumio[1430]: Cannot find translation for source Podcast
Aug 29 10:47:44 deskplayer volumio[1430]: Cannot find translation for source Spotify
Aug 29 10:47:45 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Aug 29 10:47:45 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:45 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:45 deskplayer go-librespot[2358]: go-librespot daemon starting...
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=debug msg="app state loaded"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=info msg="zeroconf server listening on port 44395"
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:45 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Aug 29 10:47:45 deskplayer volumio-remote-updater[600]: Test mode disabled
Aug 29 10:47:45 deskplayer volumio-remote-updater[600]: Alpha mode disabled
Aug 29 10:47:45 deskplayer volumio-remote-updater[600]: Alpha legacy test mode disabled
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=debug msg="obtained new client token: AAE2WsQFDFxi+HyJHKOSCtgx3ZMH5BCRBXlphIsAPiqnyft5QIQdIO0KQ7qYOtv9kNBpRKPB9XoLhElA9SQTMxB73zS9073SWVgk7+m6pkIWDTHhomMYFfZi13x54OndXE9VcC0sBNTMeDlzts+KhLxAiCVOHSmTsSu/8L97RsdhEyJKaXUpBMH/T2WDM44SSNmnUp+oV+jLGQ3SGVVF0Rvx+bVysLE6ZjSET1L6ZTJioe+NxWuqJxsc"
Aug 29 10:47:45 deskplayer volumio[1430]: 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: 17
Aug 29 10:47:45 deskplayer go-librespot[2359]: time="2026-08-29T10:47:45+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Aug 29 10:47:46 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused"
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:80"
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=debug msg="completed challenge"
Aug 29 10:47:46 deskplayer volumio[1430]: 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: 17
Aug 29 10:47:46 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:46 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:46 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:46 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:46.236+02:00 level=INFO msg="system info for 9a6de8c604b6606acc51141dd634b33c" deviceName=deskplayer deviceVariant="" deviceModel= softwareVersion=""
Aug 29 10:47:46 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:46.257+02:00 level=INFO msg="bootstrapping state" hasInternet=true
Aug 29 10:47:46 deskplayer volumio[1430]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 29 10:47:46 deskplayer go-librespot[2359]: time="2026-08-29T10:47:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:46 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:46 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:46 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:46 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:46 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:46 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:47 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18
Aug 29 10:47:47 deskplayer volumio-remote-updater[600]: Test mode disabled
Aug 29 10:47:47 deskplayer volumio-remote-updater[600]: Alpha mode disabled
Aug 29 10:47:47 deskplayer volumio-remote-updater[600]: Alpha legacy test mode disabled
Aug 29 10:47:49 deskplayer pirate_port[1714]: [2026-08-29T08:47:49.108Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' }
Aug 29 10:47:49 deskplayer volumio[1430]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 29 10:47:49 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 29 10:47:49 deskplayer volumio[1430]: info: AutoStart - Check #7/60 - VOLUMIO_SYSTEM_STATUS = starting
Aug 29 10:47:49 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:47:49 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Aug 29 10:47:49 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:49 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:49 deskplayer go-librespot[2375]: go-librespot daemon starting...
Aug 29 10:47:49 deskplayer go-librespot[2376]: time="2026-08-29T10:47:49+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:49 deskplayer go-librespot[2376]: time="2026-08-29T10:47:49+02:00" level=debug msg="app state loaded"
Aug 29 10:47:49 deskplayer go-librespot[2376]: time="2026-08-29T10:47:49+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:49 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:49 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:49.867+02: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 10:47:49 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:49.877+02: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 10:47:49 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:49.878+02: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 10:47:49 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=info msg="zeroconf server listening on port 40123"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:50 deskplayer volumio[1430]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 20
Aug 29 10:47:50 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="obtained new client token: AAEGwlPFpeUXtQmwMzunV4JYLTgQZ55YL42kEDcTtwrb6U5MfwVBhi4v84uVoFkm/04LeEUhJiR+1z2pjgjfAuOk/myohf8RYBEbDMJTL1E4gfC2yum150J288qYbAG44HICjDlu+B7eQn5BWhyJfNXU/O850BLxwS+WfALMXZNA2AMJqYXkCg8w3ADNX8dumizINxlMmw9sc7tq/xwvKxssB4Bxv3qK2Y8K3oEsNkSByIVndidRbrr+"
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=debug msg="completed challenge"
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:50 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:50 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:50 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:50 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:50 deskplayer go-librespot[2376]: time="2026-08-29T10:47:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:50 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:50 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:51 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Aug 29 10:47:51 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Aug 29 10:47:51 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:51.545+02:00 level=INFO msg="enabling local network discovery"
Aug 29 10:47:51 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:51.589+02:00 level=INFO msg="enabling BLE discovery"
Aug 29 10:47:51 deskplayer sudo[2390]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 29 10:47:51 deskplayer sudo[2390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:47:51 deskplayer sudo[2390]: pam_unix(sudo:session): session closed for user root
Aug 29 10:47:51 deskplayer sudo[2389]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 29 10:47:51 deskplayer sudo[2389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:47:52 deskplayer volumio[1430]: info: MyVolumio login type: Token
Aug 29 10:47:52 deskplayer sudo[2389]: pam_unix(sudo:session): session closed for user root
Aug 29 10:47:52 deskplayer volumio[1430]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 20
Aug 29 10:47:52 deskplayer volumio[1430]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 21
Aug 29 10:47:52 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:47:52.627+02:00 level=INFO msg="service successfully established" component=discovery/localnet
Aug 29 10:47:53 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22
Aug 29 10:47:53 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Aug 29 10:47:53 deskplayer volumio[1430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21
Aug 29 10:47:54 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Aug 29 10:47:54 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:54 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:47:54 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:54 deskplayer go-librespot[2409]: go-librespot daemon starting...
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=debug msg="app state loaded"
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:54 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 29 10:47:54 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:54 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:54 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:54 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:54 deskplayer volumio[1430]: info: Listing playlists
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:54 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:54 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:54 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:54 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:47:54 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:54 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=info msg="zeroconf server listening on port 45011"
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:54 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Aug 29 10:47:54 deskplayer volumio[1430]: info: AutoStart - Check #8/60 - VOLUMIO_SYSTEM_STATUS = starting
Aug 29 10:47:54 deskplayer go-librespot[2410]: time="2026-08-29T10:47:54+02:00" level=debug msg="obtained new client token: AAFf4iNc0LOtcP6ggkSVhYGB8GEozs3xaTzxq1TSY6WRQq11DX53RGCn5Afg/OPHVXqwgNCJ9TinabKOSOq/9YPy5WiCzI0ONV9mxxreTExLpQyq7C9YdZkEW/4Geco3WZS7GLdyl1VmNVBTpVAm8L4nUm4ZAO64RtX/keOfFEpMQe2F7pBBdUomNiezM7VtRmV9fVHc8QO1d71FJyLLqHJUTQFAk+obZWoytErM+iBrv8Fvt2PbaOnN"
Aug 29 10:47:55 deskplayer go-librespot[2410]: time="2026-08-29T10:47:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:55 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:55 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:55 deskplayer go-librespot[2410]: time="2026-08-29T10:47:55+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:55 deskplayer go-librespot[2410]: time="2026-08-29T10:47:55+02:00" level=debug msg="completed challenge"
Aug 29 10:47:55 deskplayer go-librespot[2410]: time="2026-08-29T10:47:55+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:55 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:47:55 deskplayer go-librespot[2410]: time="2026-08-29T10:47:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:55 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:55 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:47:55 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:55 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:56 deskplayer volumio[1430]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Aug 29 10:47:56 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:47:56 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:56 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 29 10:47:56 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 29 10:47:57 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 29 10:47:57 deskplayer volumio[1430]: info: MyVolumio login type: Token
Aug 29 10:47:57 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 29 10:47:57 deskplayer volumio[1430]: info: MyVolumio login type: Token
Aug 29 10:47:57 deskplayer volumio[1430]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Aug 29 10:47:57 deskplayer volumio[1430]: info: Completed starting MyVolumio Plugin
Aug 29 10:47:57 deskplayer volumio[1430]: [Metrics] CommandRouter: 139s 518.47ms
Aug 29 10:47:57 deskplayer volumio[1430]: info: CoreCommandRouter::volumiosetStartupVolume
Aug 29 10:47:57 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 10:47:57 deskplayer volumio[1430]: info: VolumeController:: Setting startup Volume 50
Aug 29 10:47:57 deskplayer volumio[1430]: info: VolumeController::SetAlsaVolume50
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::Close All Modals sent
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::Close All Modals sent
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:47:58 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:47:58 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Aug 29 10:47:58 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:58 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:47:58 deskplayer go-librespot[2426]: go-librespot daemon starting...
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Aug 29 10:47:58 deskplayer go-librespot[2427]: time="2026-08-29T10:47:58+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:47:58 deskplayer go-librespot[2427]: time="2026-08-29T10:47:58+02:00" level=debug msg="app state loaded"
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:58 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:47:58 deskplayer go-librespot[2427]: time="2026-08-29T10:47:58+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:47:58 deskplayer volumio[1430]: info: MyVolumio token set successfully
Aug 29 10:47:58 deskplayer volumio[1430]: info: MYVOLUMIO: Adding device
Aug 29 10:47:58 deskplayer volumio[1430]: info: MYVOLUMIO: Evaluating Server
Aug 29 10:47:58 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:47:59 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Aug 29 10:47:59 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=info msg="zeroconf server listening on port 40007"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="obtained new client token: AAGhe0jLKvVyoi4sTwn4pTrqE7gOSTNNJvEzTae7ld4mNOQlVILElpfh5U7Xx8E1/NCPpcSsdTIZhpG53dGcYwUNDLEVhy2vNKYHuWdBBtz+uYmcoIryuMui3X5iUuav7Hr/8eyQXeIBn9hlMQcugXsrQf0+jhD8EKfH2FK+7OUK/3IEaLAZ6SrshdN8S6EF03JFIc5hQszzuvXP2qPm/yGdEJnvRA8kcz5S9Y3Q4R6XMNokT+ZY+a9k"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="completed keyexchange"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=debug msg="completed challenge"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:47:59 deskplayer go-librespot[2427]: time="2026-08-29T10:47:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:47:59 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:47:59 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Aug 29 10:48:01 deskplayer volumio[1430]: info: AutoStart - Check #9/60 - VOLUMIO_SYSTEM_STATUS = starting
Aug 29 10:48:01 deskplayer volumio[1430]: info: MyVolumio status changed
Aug 29 10:48:01 deskplayer volumio[1430]: info: Streaming services startup
Aug 29 10:48:01 deskplayer volumio[1430]: info: Starting Streaming Daemon
Aug 29 10:48:02 deskplayer volumio[1430]: info: Removing browser output: myVolumio user plan is not superstar
Aug 29 10:48:02 deskplayer volumio[1430]: info: Removing audio output:
Aug 29 10:48:02 deskplayer volumio[1430]: info: Stoppping Tunnel 1
Aug 29 10:48:02 deskplayer sudo[2481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Aug 29 10:48:02 deskplayer sudo[2481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:48:02 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:48:02 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:48:02 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:48:02 deskplayer sudo[2483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Aug 29 10:48:02 deskplayer sudo[2483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:48:02 deskplayer sudo[2481]: pam_unix(sudo:session): session closed for user root
Aug 29 10:48:02 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:48:02 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:48:02 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer sudo[2483]: pam_unix(sudo:session): session closed for user root
Aug 29 10:48:03 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Aug 29 10:48:03 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:03 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:03 deskplayer go-librespot[2486]: go-librespot daemon starting...
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="app state loaded"
Aug 29 10:48:03 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:03 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: socket hang up
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="zeroconf server listening on port 37917"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="obtained new client token: AAEQBBmUjlDLU783z0AHUyc3D56QdPT4XVVxYl9I72YbyThpLLSE9GEOkfzYHOaWd3CE5t1y1FAZ4sxX5TY/w/B0/KmkPbD9Q4fMq1DT13u0JP5yuwJ3q7CMW4UlSPTdBA8y5l1yK/TU8rjYk1IkVHyD6udyg9D+0Zy3JOoYrP3+5zsKBjaeAJbZg2uYL2Hs8fX3SUyMJoa6XDAW8ab2M0yMU7Bey5G1SvXloufNRCQjL2hDmA2qBv/K"
Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=debug msg="completed challenge"
Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:04 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:04 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:04 deskplayer volumio[1430]: info: Remote SSH Stopped
Aug 29 10:48:04 deskplayer volumio[1430]: error: Cannot start Volumio Streaming Daemon
Aug 29 10:48:04 deskplayer volumio[1430]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Aug 29 10:48:04 deskplayer volumio[1430]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Aug 29 10:48:05 deskplayer volumio[1430]: info: BOOT COMPLETED
Aug 29 10:48:05 deskplayer volumio[1430]: info: Setting Geolocation for MyVolumio to eu4
Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:05 deskplayer volumio[1430]: info: Successfully Added MyVolumio device
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Aug 29 10:48:06 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:48:06 deskplayer volumio[1430]: info: Updating MyVolumio device info
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 10:48:06 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Check #10/60 - VOLUMIO_SYSTEM_STATUS = ready
Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - System ready state CONFIRMED after 10 checks
Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Setting startup volume to 50
Aug 29 10:48:06 deskplayer volumio[1430]: info: VolumeController::SetAlsaVolume50
Aug 29 10:48:06 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:06.934+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:06.934+02:00
Aug 29 10:48:06 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:06.934+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:06.934+02:00
Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Startup volume set successfully to 50
Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Applying additional delay of 5000ms before playback
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:06 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:07 deskplayer volumio[1430]: info: Successfully Updated MyVolumio device
Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.176+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:07.176+02:00
Aug 29 10:48:07 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Aug 29 10:48:07 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:07 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:07 deskplayer go-librespot[2511]: go-librespot daemon starting...
Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.668+02:00 level=ERROR msg="failed to broadcast user info" component=state error="failed to get logged user: could not get custom token: failed to fetch custom token: Get \"https://functions.volumio.cloud/api/v1/getCustomToken?idToken=eyJhbGciOiJSUzI1NiIsImtpZCI6ImFhMmNiOTcyNTIzMzc3ZWRlMjE2MzQwYmNkNTg4MTA0MTQxZTYxY2MiLCJ0eXAiOiJKV1QifQ.eyJpc3MiOiJodHRwczovL3NlY3VyZXRva2VuLmdvb2dsZS5jb20vbXl2b2x1bWlvIiwiYXVkIjoibXl2b2x1bWlvIiwiYXV0aF90aW1lIjoxNzg3OTkzMjg2LCJ1c2VyX2lkIjoiMHVIOGJKdjR1Z05CNk16dzZ3NUlOVk13QWY1MiIsInN1YiI6IjB1SDhiSnY0dWdOQjZNenc2dzVJTlZNd0FmNTIiLCJpYXQiOjE3ODc5OTMyODYsImV4cCI6MTc4Nzk5Njg4NiwiZW1haWwiOiJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiZmlyZWJhc2UiOnsiaWRlbnRpdGllcyI6eyJlbWFpbCI6WyJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iXX0sInNpZ25faW5fcHJvdmlkZXIiOiJjdXN0b20ifX0.mhPmtg-GHaEqwhoqnTABRHLMU50gwdMWMCxnCwozOSCyMNyhxUOZkcYWJaaLXKagytPMWGLdVYe67x1hckeajtObiyuBBjC0KX_MkKv2H6zRwgLibxiLof8T9SVghFjC7a9U2VlNANZ-IKMJxvHjmcLbrf47oS-_OUmZdiyZK-H0WIXcmlXZO_cGxBC7pnsRG7MNdy8Es_apthU2znnMYDiEGjzLzfvxeZFGcjwbK615kQDHnJP4bH5gcCTNORN9WP0t8BU03bNUU8jN9CjXBZ4mZJxddAb4LW-AbEfCdv4jsc9Akobcp66Px6bg3X06sKeaHl6V-hPrgcWGPJ9cgA\": context deadline exceeded"
Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=debug msg="app state loaded"
Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.752+02:00 level=ERROR msg="failed to broadcast user info" component=state error="failed to get logged user: could not get custom token: failed to fetch custom token: Get \"https://functions.volumio.cloud/api/v1/getCustomToken?idToken=eyJhbGciOiJSUzI1NiIsImtpZCI6ImFhMmNiOTcyNTIzMzc3ZWRlMjE2MzQwYmNkNTg4MTA0MTQxZTYxY2MiLCJ0eXAiOiJKV1QifQ.eyJpc3MiOiJodHRwczovL3NlY3VyZXRva2VuLmdvb2dsZS5jb20vbXl2b2x1bWlvIiwiYXVkIjoibXl2b2x1bWlvIiwiYXV0aF90aW1lIjoxNzg3OTkzMjg2LCJ1c2VyX2lkIjoiMHVIOGJKdjR1Z05CNk16dzZ3NUlOVk13QWY1MiIsInN1YiI6IjB1SDhiSnY0dWdOQjZNenc2dzVJTlZNd0FmNTIiLCJpYXQiOjE3ODc5OTMyODYsImV4cCI6MTc4Nzk5Njg4NiwiZW1haWwiOiJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiZmlyZWJhc2UiOnsiaWRlbnRpdGllcyI6eyJlbWFpbCI6WyJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iXX0sInNpZ25faW5fcHJvdmlkZXIiOiJjdXN0b20ifX0.mhPmtg-GHaEqwhoqnTABRHLMU50gwdMWMCxnCwozOSCyMNyhxUOZkcYWJaaLXKagytPMWGLdVYe67x1hckeajtObiyuBBjC0KX_MkKv2H6zRwgLibxiLof8T9SVghFjC7a9U2VlNANZ-IKMJxvHjmcLbrf47oS-_OUmZdiyZK-H0WIXcmlXZO_cGxBC7pnsRG7MNdy8Es_apthU2znnMYDiEGjzLzfvxeZFGcjwbK615kQDHnJP4bH5gcCTNORN9WP0t8BU03bNUU8jN9CjXBZ4mZJxddAb4LW-AbEfCdv4jsc9Akobcp66Px6bg3X06sKeaHl6V-hPrgcWGPJ9cgA\": context deadline exceeded"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="zeroconf server listening on port 41893"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="obtained new client token: AAHzc7xuH04nuzknLad4y+IZXroqG19jc/y6Fi5gHEuLs9HkTxhgp+6UNWIU1kHQXMJFf1/Iu4tFGg337VCxhNwGxo3FyH6sv8l2zGYTDXpMKA6bJrZLibNieVk2hXPKD0Y3n/agQA9EAx5XbaBjCGnGGmeqU6vX+jCmoj6YxkU+N8XsU4cbt40z/6aQB0QGws+1x/tEPvzwGWhLV4DWgazQn0kpysIxHWKqUc4TYAwABAvOmCz4tFds"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="completed challenge"
Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:08 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 29 10:48:08 deskplayer volumio[1430]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Aug 29 10:48:08 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Aug 29 10:48:09 deskplayer go-librespot[2512]: time="2026-08-29T10:48:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:09 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:09 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:09 deskplayer volumio[1430]: info: Received Get System Version
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 29 10:48:09 deskplayer volumio[1430]: info: Received Get System Info
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 10:48:09 deskplayer volumio[1430]: info: Discovery: Getting this device information
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState
Aug 29 10:48:09 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 10:48:09 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:48:09 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - startPlayback called
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetQueue
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::getQueue
Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getQueue
Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - Queue has 18 items
Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - Playing from position 0
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPlay
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::play index 0
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::stop
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::play index undefined
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::startPlaybackTimer
Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:12 deskplayer volumio[1430]: info: [1787993292294] ControllerWebradio::clearAddPlayTrack
Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand stop
Aug 29 10:48:12 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Aug 29 10:48:12 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:12 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:12 deskplayer go-librespot[2539]: go-librespot daemon starting...
Aug 29 10:48:12 deskplayer volumio[1430]: info: sendMpdCommand stop took 105 milliseconds
Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand clear
Aug 29 10:48:12 deskplayer volumio[1430]: info:
Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=debug msg="app state loaded"
Aug 29 10:48:12 deskplayer volumio[1430]: info: sendMpdCommand clear took 81 milliseconds
Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand load "https://orf-live.ors-shoutcast.at/oe1-q2a"
Aug 29 10:48:12 deskplayer volumio[1430]: info:
Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:12 deskplayer volumio[1430]: info:
Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:12 deskplayer volumio[1430]: error: updateQueue error: null
Aug 29 10:48:12 deskplayer volumio[1430]: info: ------------------------------ 245ms
Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="zeroconf server listening on port 34439"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs
Aug 29 10:48:13 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="obtained new client token: AAFZGm0opykwtOdDg622UHXKW5fgKP5haX6i7DCboE0yzeEpsVr2Or8EofRvIkdmDauYwY6k2YjcMrtyvWhjjPWnIfyw8/ddIAMSmAyXzqlz3AWGVahHQrYp4fF5JzoWe4XhLgWycnhReyqVVT+oo4dRmiW0NRt1j689ihxETJD+WWOOALH0KcD5HDP0jdrMIMcB2UjVm07jPjE69zakCDLfXSI/v6hqcdMHvFNYKUbuhl58AYUz/mAA"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:13 deskplayer volumio[1430]: info: Received Get System Version
Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 29 10:48:13 deskplayer volumio[1430]: error: updateQueue error: null
Aug 29 10:48:13 deskplayer volumio[1430]: error: updateQueue error: null
Aug 29 10:48:13 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand add "https://orf-live.ors-shoutcast.at/oe1-q2a"
Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 1085ms
Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 1024ms
Aug 29 10:48:13 deskplayer volumio[1430]: info:
Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="new websocket client"
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="completed challenge"
Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:13 deskplayer volumio[1430]: info: sendMpdCommand add "https://orf-live.ors-shoutcast.at/oe1-q2a" took 144 milliseconds
Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 29 10:48:13 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand play
Aug 29 10:48:13 deskplayer volumio[1430]: info:
Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:13 deskplayer volumio[1430]: info:
Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:13 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:13 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 267ms
Aug 29 10:48:13 deskplayer volumio[1430]: info: sendMpdCommand play took 142 milliseconds
Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 151ms
Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 92ms
Aug 29 10:48:13 deskplayer volumio[1430]: info: Connection to go-librespot Websocket established
Aug 29 10:48:13 deskplayer volumio[1430]: info:
Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info: Connection to go-librespot Websocket closed
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 386 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 224 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 171 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:14 deskplayer volumio[1430]: info:
Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:14 deskplayer volumio[1430]: info: ------------------------------ 336ms
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 265 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 227 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 226 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 184 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: info: ------------------------------ 206ms
Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 183 milliseconds
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:14 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":988,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus stop
Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:14 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1230,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:14 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:14 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1230,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:15 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1332ms
Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1603ms
Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1574ms
Aug 29 10:48:15 deskplayer volumio[1430]: info:
Aug 29 10:48:15 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:15 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:15 deskplayer volumio[1430]: info:
Aug 29 10:48:15 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1196ms
Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand status took 1171 milliseconds
Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1014 milliseconds
Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1011 milliseconds
Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1357,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:15 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:15 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:16 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1609,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:16 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:16 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:16 deskplayer volumio[1430]: info: ------------------------------ 2305ms
Aug 29 10:48:16 deskplayer volumio[1430]: info: ------------------------------ 2007ms
Aug 29 10:48:16 deskplayer volumio[1430]: info:
Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:16 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:16 deskplayer volumio[1430]: info:
Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:16 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:16 deskplayer volumio[1430]: info:
Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update
Aug 29 10:48:16 deskplayer volumio[1430]: info: Ignoring MPD Status Update
Aug 29 10:48:16 deskplayer volumio[1430]: info:
Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player
Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::getState
Aug 29 10:48:16 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 10:48:17 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Aug 29 10:48:17 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:17 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:17 deskplayer go-librespot[2581]: go-librespot daemon starting...
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=debug msg="app state loaded"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:17 deskplayer volumio[1430]: info: Getting Spotify volume
Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 1563ms
Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 1513 milliseconds
Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1548 milliseconds
Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 529ms
Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 438 milliseconds
Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 437ms
Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 461 milliseconds
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 10:48:17 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:17 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1609,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:17 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:17 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="zeroconf server listening on port 43367"
Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="obtained new client token: AAHywC710MHqGT8DTHG98eKnhUbulk+ezTfAvyPZ4W/9+XafeIJojNO+wQVYY1fx4Lj4bUzMB3NfCu1+8KFdOfIKzJbJmCFJ3cZQtPEnr+7CAtdomebJYG6OGFWNFldmOIEYhobkNUXZ3y5RcW278Jv/WVyEcoH5hB12vXRwqGQkGA1IomaguVVo9YNHz22lZEhfyNxeUDJHzxm1c5h8ifvVr4GIx5sCWxs8GrKX8mod7xGd8Atj2Q=="
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:18 deskplayer volumio[1430]: info: ------------------------------ 3470ms
Aug 29 10:48:18 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 729 milliseconds
Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 687 milliseconds
Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 686 milliseconds
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo
Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="completed challenge"
Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2861,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:18 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:18 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3981,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3981,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"}
Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play
Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState
Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState
Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 3611ms
Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 2475ms
Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 2465ms
Aug 29 10:48:19 deskplayer volumio[1430]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 10:48:19 deskplayer volumio[1430]: Error: socket hang up
Aug 29 10:48:19 deskplayer volumio[1430]: at connResetException (node:internal/errors:720:14)
Aug 29 10:48:19 deskplayer volumio[1430]: at Socket.socketOnEnd (node:_http_client:519:23)
Aug 29 10:48:19 deskplayer volumio[1430]: at Socket.emit (node:events:526:35)
Aug 29 10:48:19 deskplayer volumio[1430]: at endReadableNT (node:internal/streams/readable:1376:12)
Aug 29 10:48:19 deskplayer volumio[1430]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Aug 29 10:48:19 deskplayer volumio[1430]: code: 'ECONNRESET',
Aug 29 10:48:19 deskplayer volumio[1430]: response: undefined
Aug 29 10:48:19 deskplayer volumio[1430]: }
Aug 29 10:48:19 deskplayer volumio[1430]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 10:48:21 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Aug 29 10:48:21 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:21 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:21 deskplayer go-librespot[2598]: go-librespot daemon starting...
Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=debug msg="app state loaded"
Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="zeroconf server listening on port 36695"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="obtained new client token: AAGFP1bmSY6xTtJqr06GbsBTuX1jxWZ4CPKi/6yuZc64hvux9EWiCed6VqyOU6XQBiG8liSmahFnvot7huYq9i/QNmrTgIYkfABR6Q7WHk8iCIXmAsXxlMkr+pB43/zsgC3daN8DG9071JhQa/xhJTrPfzWGf3ErpfQe6enlwpSWCC2awr14+Uwtem8g9DLjHvs+nSDxD0oVaC6zn1P8Gmi2jK1TiQfmuHJ7CUT7xHKDcG/63b0USbYT"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="completed challenge"
Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:23 deskplayer go-librespot[2599]: time="2026-08-29T10:48:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:23 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:23 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:26 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Aug 29 10:48:26 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:26 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:26 deskplayer go-librespot[2632]: go-librespot daemon starting...
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=debug msg="app state loaded"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="zeroconf server listening on port 36245"
Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="obtained new client token: AAHJp6H6zlT1dobNhgOrBfSyZBQk/sJJw+3lJp6V0zj99f2Vkvorb/eeSnE2zRSGOtP5PjUnJJ06yMBlsCsuvkulfKo9qcMDr5jHStdEe2K/XrRKdcbM9PLhRkF3a1LWK5A7ImHcn6XXzZvB/wal5wOK/Vg2j7VzfcnM7z8cH/JR5U9FR7ab5EzeU/gUPQbuZnhAa2Q26DBB1RWw/CDlpdJGKt87BlDr+D5QQFtp0yVoR8GAK0WgAw=="
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="completed challenge"
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:27 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:27 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:30 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Aug 29 10:48:30 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:30 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:30 deskplayer go-librespot[2643]: go-librespot daemon starting...
Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=debug msg="app state loaded"
Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="zeroconf server listening on port 37583"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="obtained new client token: AAGj4l8hYrYEpzY1aRYGtqCkPTGCVVNiKUbJd4cfQRcVuGkrEkR70AkDJLiq7CiSLExeIKlqJPA/ieFqMYtsHKcoMK7nPaFNovyavOO/wNG/odfNv4Z+CdOrl7HnHVtSoBwyRD6xSWOO+armHo78HfGziAo8cDLmctH3N+8fW//wecci4lHhlqtR/i1vhL9MgDUXscbk8ZSHpD0Z46o63apcLoXNwQLqM7PcD9obv93DOGdyVUhi2Ijr"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="completed challenge"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:31 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:31 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:35 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Aug 29 10:48:35 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:35 deskplayer sudo[2655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 10:47'
Aug 29 10:48:35 deskplayer sudo[2655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 10:48:35 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 29 10:48:35 deskplayer go-librespot[2656]: go-librespot daemon starting...
Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=info msg="running go-librespot 0.7.1"
Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=debug msg="app state loaded"
Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="zeroconf server listening on port 34615"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="obtained new client token: AAFk1PSDDzwcDI3VOo3JoN0442bMFZB7Kmh7WF06TFN6H5oZ6rDUJrcVZYYhCy7q52zCW4yJrHDYOnIFHK2zTxBaqH7hhJi2S+/oi8rRZ1cK0nsl+yTTpqH8qxWnuXq0KNyCsr7FMl+SQaMh4W0OzNBnv0LVg7AJG/ce/O+wigCl7zqGZ0Pv+lw9NTeNdlt26oZV2L1Omik44aFXRjKnbfx9T0RvSsU/E5qHzJgJpzlNm4k1CaRrJ99b"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="completed keyexchange"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="completed challenge"
Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="authenticated AP" username="st**st"
Aug 29 10:48:37 deskplayer go-librespot[2658]: time="2026-08-29T10:48:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 29 10:48:37 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 10:48:37 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 29 10:48:39 deskplayer sshd[2681]: Accepted publickey for volumio from 192.168.1.210 port 54994 ssh2: RSA SHA256:ODKQL3gpmI5vrRENu+fRTs7eXecqGFHwdVJSLYBXV/4
Aug 29 10:48:39 deskplayer sshd[2681]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0)
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"