-- Logs begin at Fri 2026-08-28 18:21:00 CEST, end at Fri 2026-08-28 19:35:05 CEST. --
Aug 28 19:34:00 volumio go-librespot[30365]: time="2026-08-28T19:34:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:00 volumio go-librespot[30365]: time="2026-08-28T19:34:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:00 volumio go-librespot[30365]: time="2026-08-28T19:34:00+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:00 volumio go-librespot[30365]: time="2026-08-28T19:34:00+02:00" level=debug msg="completed challenge"
Aug 28 19:34:00 volumio go-librespot[30365]: time="2026-08-28T19:34:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:01 volumio go-librespot[30365]: time="2026-08-28T19:34:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:01 volumio go-librespot[30365]: time="2026-08-28T19:34:01+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:01 volumio go-librespot[30365]: time="2026-08-28T19:34:01+02:00" level=debug msg="completed challenge"
Aug 28 19:34:01 volumio go-librespot[30365]: time="2026-08-28T19:34:01+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:01 volumio go-librespot[30365]: time="2026-08-28T19:34:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:01 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:02 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:02 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:02 volumio volumio[899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Aug 28 19:34:02 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 345)
Aug 28 19:34:02 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:02 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:02 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:04 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:04 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 741.
Aug 28 19:34:04 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:04 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:04 volumio go-librespot[30405]: go-librespot daemon starting...
Aug 28 19:34:04 volumio go-librespot[30405]: time="2026-08-28T19:34:04+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:04 volumio go-librespot[30405]: time="2026-08-28T19:34:04+02:00" level=debug msg="app state loaded"
Aug 28 19:34:04 volumio go-librespot[30405]: time="2026-08-28T19:34:04+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:04 volumio go-librespot[30405]: time="2026-08-28T19:34:04+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+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 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+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 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=info msg="zeroconf server listening on port 43577"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=debug msg="obtained new client token: AAHpsFKcU5dpUKwEIL7ffG0DOvHUG3aTKarARCfAS0JO+R6e2g/8YIrq+CS9udFhYVYXv+Fl4iI8QdgoMsE4WcLrIQELo/e5XVxsCm5m5kXcMLwDoyhfKRYH5fRpgW5TGYXm4N6FAspkLDVhVQZp1yVhQmm5xeC/ItkLBWI86rRjrB1IL5ZdiIK2dO8OA0VEHn06kzSK3sI5EoNb3w6olG4Q0qWwdEin/OeU6Xf3Z2r45wo5vLboyQ=="
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=debug msg="completed challenge"
Aug 28 19:34:05 volumio go-librespot[30405]: time="2026-08-28T19:34:05+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=debug msg="completed challenge"
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused"
Aug 28 19:34:06 volumio go-librespot[30405]: time="2026-08-28T19:34:06+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="completed challenge"
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:07 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="new websocket client"
Aug 28 19:34:07 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:443"
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:07 volumio go-librespot[30405]: time="2026-08-28T19:34:07+02:00" level=debug msg="completed challenge"
Aug 28 19:34:08 volumio go-librespot[30405]: time="2026-08-28T19:34:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:08 volumio go-librespot[30405]: time="2026-08-28T19:34:08+02:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Aug 28 19:34:09 volumio go-librespot[30405]: time="2026-08-28T19:34:09+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:09 volumio go-librespot[30405]: time="2026-08-28T19:34:09+02:00" level=debug msg="completed challenge"
Aug 28 19:34:09 volumio go-librespot[30405]: time="2026-08-28T19:34:09+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:10 volumio go-librespot[30405]: time="2026-08-28T19:34:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:10 volumio go-librespot[30405]: time="2026-08-28T19:34:10+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:10 volumio go-librespot[30405]: time="2026-08-28T19:34:10+02:00" level=debug msg="completed challenge"
Aug 28 19:34:10 volumio go-librespot[30405]: time="2026-08-28T19:34:10+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:10 volumio go-librespot[30405]: time="2026-08-28T19:34:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:10 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:10 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:10 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:10 volumio volumio[899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Aug 28 19:34:10 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 346)
Aug 28 19:34:10 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:10 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:10 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:13 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:13 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 742.
Aug 28 19:34:13 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:13 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:13 volumio go-librespot[30448]: go-librespot daemon starting...
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="app state loaded"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+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 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+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 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=info msg="zeroconf server listening on port 45315"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="obtained new client token: AAGKB48nJgj/uly+qbGn/XcGjU9hUjDpjQyVo7T1eb32WmSKvdhyfacojnupgWv89cmiMwuGTnbkO80Yo3cPTNtF7HzDWRsvF6/HKOynm96OPjHvUub7xs3nwfc8ZE3kmrjpPzAoUvHe/9MFflFKbAic+uyra+xZ9Sa60RYgM0TLLdT45cfrcqsw33Ja6HpD9xm5RLsYyGrXaQK9yN1NA8FTLRydwqN5WWU5Q98JlNbejMdkZuxok5jb"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:13 volumio go-librespot[30448]: time="2026-08-28T19:34:13+02:00" level=debug msg="completed challenge"
Aug 28 19:34:14 volumio go-librespot[30448]: time="2026-08-28T19:34:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:14 volumio go-librespot[30448]: time="2026-08-28T19:34:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:14 volumio go-librespot[30448]: time="2026-08-28T19:34:14+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:14 volumio go-librespot[30448]: time="2026-08-28T19:34:14+02:00" level=debug msg="completed challenge"
Aug 28 19:34:14 volumio go-librespot[30448]: time="2026-08-28T19:34:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:15 volumio go-librespot[30448]: time="2026-08-28T19:34:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:80"
Aug 28 19:34:15 volumio go-librespot[30448]: time="2026-08-28T19:34:15+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:15 volumio go-librespot[30448]: time="2026-08-28T19:34:15+02:00" level=debug msg="completed challenge"
Aug 28 19:34:15 volumio go-librespot[30448]: time="2026-08-28T19:34:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:16 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:16 volumio go-librespot[30448]: time="2026-08-28T19:34:16+02:00" level=debug msg="new websocket client"
Aug 28 19:34:16 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:16 volumio go-librespot[30448]: time="2026-08-28T19:34:16+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Aug 28 19:34:16 volumio go-librespot[30448]: time="2026-08-28T19:34:16+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:16 volumio go-librespot[30448]: time="2026-08-28T19:34:16+02:00" level=debug msg="completed challenge"
Aug 28 19:34:16 volumio go-librespot[30448]: time="2026-08-28T19:34:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:17 volumio go-librespot[30448]: time="2026-08-28T19:34:17+02:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Aug 28 19:34:17 volumio go-librespot[30448]: time="2026-08-28T19:34:17+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:17 volumio go-librespot[30448]: time="2026-08-28T19:34:17+02:00" level=debug msg="completed challenge"
Aug 28 19:34:17 volumio go-librespot[30448]: time="2026-08-28T19:34:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:18 volumio go-librespot[30448]: time="2026-08-28T19:34:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:80"
Aug 28 19:34:18 volumio go-librespot[30448]: time="2026-08-28T19:34:18+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:18 volumio go-librespot[30448]: time="2026-08-28T19:34:18+02:00" level=debug msg="completed challenge"
Aug 28 19:34:18 volumio go-librespot[30448]: time="2026-08-28T19:34:18+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:18 volumio go-librespot[30448]: time="2026-08-28T19:34:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:18 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:19 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:19 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:19 volumio volumio[899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Aug 28 19:34:19 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 347)
Aug 28 19:34:19 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:19 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:19 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:21 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:21 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 743.
Aug 28 19:34:21 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:21 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:21 volumio go-librespot[30526]: go-librespot daemon starting...
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=debug msg="app state loaded"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+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 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+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 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=info msg="zeroconf server listening on port 45271"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:21 volumio go-librespot[30526]: time="2026-08-28T19:34:21+02:00" level=debug msg="obtained new client token: AAFBG1rNqA8DKCedu2EEwftnUmp11T4v8X3z2oAf56+1CEv+xC+5FNeKhDFhxRk4Khy4fzSMVUu09pu1f3ix9BDX1ccterCqGknv98j7iv8///TzSIdOGN0mTwumwJM7vgjIG1LEUF8yYcxBsQf/yo0f53r/t6KxYw73DNvcFNubY5Rnbn4pptsLSS2KZiYVIQWKfVOgEthHDpsjV/ENbDr8LDVIFED1AOS+ynWNR9JpzrY8UMTvU43u"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="completed challenge"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=debug msg="completed challenge"
Aug 28 19:34:22 volumio go-librespot[30526]: time="2026-08-28T19:34:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:23 volumio go-librespot[30526]: time="2026-08-28T19:34:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:80"
Aug 28 19:34:23 volumio go-librespot[30526]: time="2026-08-28T19:34:23+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:23 volumio go-librespot[30526]: time="2026-08-28T19:34:23+02:00" level=debug msg="completed challenge"
Aug 28 19:34:23 volumio go-librespot[30526]: time="2026-08-28T19:34:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:24 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:24 volumio go-librespot[30526]: time="2026-08-28T19:34:24+02:00" level=debug msg="new websocket client"
Aug 28 19:34:24 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:24 volumio go-librespot[30526]: time="2026-08-28T19:34:24+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Aug 28 19:34:24 volumio go-librespot[30526]: time="2026-08-28T19:34:24+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:24 volumio go-librespot[30526]: time="2026-08-28T19:34:24+02:00" level=debug msg="completed challenge"
Aug 28 19:34:24 volumio go-librespot[30526]: time="2026-08-28T19:34:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:25 volumio go-librespot[30526]: time="2026-08-28T19:34:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:443"
Aug 28 19:34:25 volumio go-librespot[30526]: time="2026-08-28T19:34:25+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:25 volumio go-librespot[30526]: time="2026-08-28T19:34:25+02:00" level=debug msg="completed challenge"
Aug 28 19:34:25 volumio go-librespot[30526]: time="2026-08-28T19:34:25+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:26 volumio go-librespot[30526]: time="2026-08-28T19:34:26+02:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Aug 28 19:34:26 volumio go-librespot[30526]: time="2026-08-28T19:34:26+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:26 volumio go-librespot[30526]: time="2026-08-28T19:34:26+02:00" level=debug msg="completed challenge"
Aug 28 19:34:26 volumio go-librespot[30526]: time="2026-08-28T19:34:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:26 volumio go-librespot[30526]: time="2026-08-28T19:34:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:26 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:27 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:27 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:27 volumio volumio[899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Aug 28 19:34:27 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 348)
Aug 28 19:34:27 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:27 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:27 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:29 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:29 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 744.
Aug 28 19:34:29 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:29 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:29 volumio go-librespot[30570]: go-librespot daemon starting...
Aug 28 19:34:29 volumio go-librespot[30570]: time="2026-08-28T19:34:29+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:29 volumio go-librespot[30570]: time="2026-08-28T19:34:29+02:00" level=debug msg="app state loaded"
Aug 28 19:34:29 volumio go-librespot[30570]: time="2026-08-28T19:34:29+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+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 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+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 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=info msg="zeroconf server listening on port 39451"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=debug msg="obtained new client token: AAH6hyv5LrQIcKX8Z++vHv8K4v54FbZ4eSjI6QGNuXZ5/xrmSQLCebliRPu77O5BY1hnVKYo7Uz68G9VQZyijKz9/yh1OQM9JgECguWGee1UYJfVSpb6kpQskedctTwWC5++UQeCHRQ7tCnyNWWLsuNbhulJ7/16V4qWWcoJFp7NAz5YMJ8Jzcyp5+fyaDFsRogi64Fda8rjRp8EzT0c2SRqX5gX/+4X701frjiAMmz4kp+O3qQoMqOV"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=debug msg="completed challenge"
Aug 28 19:34:30 volumio go-librespot[30570]: time="2026-08-28T19:34:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:31 volumio go-librespot[30570]: time="2026-08-28T19:34:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:31 volumio go-librespot[30570]: time="2026-08-28T19:34:31+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:31 volumio go-librespot[30570]: time="2026-08-28T19:34:31+02:00" level=debug msg="completed challenge"
Aug 28 19:34:31 volumio go-librespot[30570]: time="2026-08-28T19:34:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused"
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=debug msg="completed challenge"
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:32 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:32 volumio go-librespot[30570]: time="2026-08-28T19:34:32+02:00" level=debug msg="new websocket client"
Aug 28 19:34:32 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:33 volumio go-librespot[30570]: time="2026-08-28T19:34:33+02:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Aug 28 19:34:33 volumio go-librespot[30570]: time="2026-08-28T19:34:33+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:33 volumio go-librespot[30570]: time="2026-08-28T19:34:33+02:00" level=debug msg="completed challenge"
Aug 28 19:34:33 volumio go-librespot[30570]: time="2026-08-28T19:34:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:34 volumio go-librespot[30570]: time="2026-08-28T19:34:34+02:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Aug 28 19:34:34 volumio go-librespot[30570]: time="2026-08-28T19:34:34+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:34 volumio go-librespot[30570]: time="2026-08-28T19:34:34+02:00" level=debug msg="completed challenge"
Aug 28 19:34:35 volumio go-librespot[30570]: time="2026-08-28T19:34:35+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:35 volumio go-librespot[30570]: time="2026-08-28T19:34:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:35 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:35 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:35 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:35 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:36 volumio go-librespot[30570]: time="2026-08-28T19:34:36+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:36 volumio go-librespot[30570]: time="2026-08-28T19:34:36+02:00" level=debug msg="completed challenge"
Aug 28 19:34:36 volumio go-librespot[30570]: time="2026-08-28T19:34:36+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:36 volumio go-librespot[30570]: time="2026-08-28T19:34:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:36 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 28 19:34:36 volumio volumio[899]: at connResetException (internal/errors.js:607:14)
Aug 28 19:34:36 volumio volumio[899]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 28 19:34:36 volumio volumio[899]: at Socket.emit (events.js:327:22)
Aug 28 19:34:36 volumio volumio[899]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 28 19:34:36 volumio volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 28 19:34:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:36 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 349)
Aug 28 19:34:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:36 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:39 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:39 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 745.
Aug 28 19:34:39 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:39 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:39 volumio go-librespot[30613]: go-librespot daemon starting...
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=debug msg="app state loaded"
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+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 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+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 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+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 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=info msg="zeroconf server listening on port 43105"
Aug 28 19:34:39 volumio go-librespot[30613]: time="2026-08-28T19:34:39+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:40 volumio go-librespot[30613]: time="2026-08-28T19:34:40+02:00" level=debug msg="obtained new client token: AAGLAAnI0xr6FUHOpSP3vPguZS1tu9HiC8MaCrBszX3dZG0PcRk6cL5YPv9YaSt+0RtMo7L1OTOnor/MNa7BVihfpT6qDAaOcI1jxZtaCimBjC/weRVbOaRMzhbzPzC5dyJai/LPYhOj1mG4BMY2Kj0VuWphWTDAWmXleP1Ny404Xrmfk6uch0gEZtKvbWwcY2/gTTvGrtoetz1JRTC/435eMJJ0Ir8Fxjyc2H3fSXmXEP2pEJKKY/1s"
Aug 28 19:34:40 volumio go-librespot[30613]: time="2026-08-28T19:34:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:40 volumio go-librespot[30613]: time="2026-08-28T19:34:40+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:40 volumio go-librespot[30613]: time="2026-08-28T19:34:40+02:00" level=debug msg="completed challenge"
Aug 28 19:34:41 volumio go-librespot[30613]: time="2026-08-28T19:34:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:41 volumio go-librespot[30613]: time="2026-08-28T19:34:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:41 volumio go-librespot[30613]: time="2026-08-28T19:34:41+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:41 volumio go-librespot[30613]: time="2026-08-28T19:34:41+02:00" level=debug msg="completed challenge"
Aug 28 19:34:41 volumio go-librespot[30613]: time="2026-08-28T19:34:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:42 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:42 volumio go-librespot[30613]: time="2026-08-28T19:34:42+02:00" level=debug msg="new websocket client"
Aug 28 19:34:42 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:42 volumio go-librespot[30613]: time="2026-08-28T19:34:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:80"
Aug 28 19:34:42 volumio go-librespot[30613]: time="2026-08-28T19:34:42+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:42 volumio go-librespot[30613]: time="2026-08-28T19:34:42+02:00" level=debug msg="completed challenge"
Aug 28 19:34:42 volumio go-librespot[30613]: time="2026-08-28T19:34:42+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:43 volumio go-librespot[30613]: time="2026-08-28T19:34:43+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Aug 28 19:34:43 volumio go-librespot[30613]: time="2026-08-28T19:34:43+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:43 volumio go-librespot[30613]: time="2026-08-28T19:34:43+02:00" level=debug msg="completed challenge"
Aug 28 19:34:43 volumio go-librespot[30613]: time="2026-08-28T19:34:43+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:44 volumio go-librespot[30613]: time="2026-08-28T19:34:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:443"
Aug 28 19:34:44 volumio go-librespot[30613]: time="2026-08-28T19:34:44+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:44 volumio go-librespot[30613]: time="2026-08-28T19:34:44+02:00" level=debug msg="completed challenge"
Aug 28 19:34:44 volumio go-librespot[30613]: time="2026-08-28T19:34:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:45 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:45 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:45 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:45 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:45 volumio go-librespot[30613]: time="2026-08-28T19:34:45+02:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Aug 28 19:34:45 volumio go-librespot[30613]: time="2026-08-28T19:34:45+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:45 volumio go-librespot[30613]: time="2026-08-28T19:34:45+02:00" level=debug msg="completed challenge"
Aug 28 19:34:45 volumio go-librespot[30613]: time="2026-08-28T19:34:45+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:45 volumio go-librespot[30613]: time="2026-08-28T19:34:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:45 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 28 19:34:45 volumio volumio[899]: at connResetException (internal/errors.js:607:14)
Aug 28 19:34:45 volumio volumio[899]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 28 19:34:45 volumio volumio[899]: at Socket.emit (events.js:327:22)
Aug 28 19:34:45 volumio volumio[899]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 28 19:34:45 volumio volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 28 19:34:45 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 350)
Aug 28 19:34:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:45 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:34:48 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:48 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:34:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:34:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 746.
Aug 28 19:34:48 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:34:48 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:34:48 volumio go-librespot[30657]: go-librespot daemon starting...
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="app state loaded"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="stored credentials not found"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+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 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+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 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+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 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=info msg="zeroconf server listening on port 38721"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="obtained new client token: AAFrR+XIKb9M2BGAXhZ91xGRHRPMiAdtr5FBs8IKRXk2RlvzQWaOnwfNP8B2ZaJhEtbgasn3YfJO5iwdGACXIW/xUliJ8m8D3HGn+QKdP8NwVSYJnwvtEoEcWqN02lSfRFZ854fOjTQ58OSSqSFRT/cwO/2TB5Zq+2Fk76DkdbUNfY99JuRNAldbRUY22T5XVvxSBWwvFuyaEoSvM+OFWMHj6vA8MinCjEdm9hqvgAt8+K07FMwEcE4F"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=debug msg="completed challenge"
Aug 28 19:34:49 volumio go-librespot[30657]: time="2026-08-28T19:34:49+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:50 volumio go-librespot[30657]: time="2026-08-28T19:34:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Aug 28 19:34:50 volumio go-librespot[30657]: time="2026-08-28T19:34:50+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:50 volumio go-librespot[30657]: time="2026-08-28T19:34:50+02:00" level=debug msg="completed challenge"
Aug 28 19:34:50 volumio go-librespot[30657]: time="2026-08-28T19:34:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:51 volumio go-librespot[30657]: time="2026-08-28T19:34:51+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused"
Aug 28 19:34:51 volumio go-librespot[30657]: time="2026-08-28T19:34:51+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Aug 28 19:34:51 volumio go-librespot[30657]: time="2026-08-28T19:34:51+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:51 volumio go-librespot[30657]: time="2026-08-28T19:34:51+02:00" level=debug msg="completed challenge"
Aug 28 19:34:51 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:34:51 volumio go-librespot[30657]: time="2026-08-28T19:34:51+02:00" level=debug msg="new websocket client"
Aug 28 19:34:51 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:34:52 volumio go-librespot[30657]: time="2026-08-28T19:34:52+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:52 volumio go-librespot[30657]: time="2026-08-28T19:34:52+02:00" level=debug msg="connected to ap-gew1.spotify.com:443"
Aug 28 19:34:54 volumio volumio[899]: info: Getting Spotify volume
Aug 28 19:34:54 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 28 19:34:54 volumio volumio[899]: info: CoreCommandRouter::volumioGetState
Aug 28 19:34:54 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Aug 28 19:34:54 volumio go-librespot[30657]: time="2026-08-28T19:34:54+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:54 volumio go-librespot[30657]: time="2026-08-28T19:34:54+02:00" level=debug msg="completed challenge"
Aug 28 19:34:56 volumio go-librespot[30657]: time="2026-08-28T19:34:56+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:56 volumio go-librespot[30657]: time="2026-08-28T19:34:56+02:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Aug 28 19:34:57 volumio go-librespot[30657]: time="2026-08-28T19:34:57+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:57 volumio go-librespot[30657]: time="2026-08-28T19:34:57+02:00" level=debug msg="completed challenge"
Aug 28 19:34:57 volumio go-librespot[30657]: time="2026-08-28T19:34:57+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:58 volumio go-librespot[30657]: time="2026-08-28T19:34:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:34:58 volumio go-librespot[30657]: time="2026-08-28T19:34:58+02:00" level=debug msg="completed keyexchange"
Aug 28 19:34:58 volumio go-librespot[30657]: time="2026-08-28T19:34:58+02:00" level=debug msg="completed challenge"
Aug 28 19:34:58 volumio go-librespot[30657]: time="2026-08-28T19:34:58+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:58 volumio go-librespot[30657]: time="2026-08-28T19:34:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Aug 28 19:34:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 28 19:34:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 28 19:34:58 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 28 19:34:58 volumio volumio[899]: at connResetException (internal/errors.js:607:14)
Aug 28 19:34:58 volumio volumio[899]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 28 19:34:58 volumio volumio[899]: at Socket.emit (events.js:327:22)
Aug 28 19:34:58 volumio volumio[899]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 28 19:34:58 volumio volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 28 19:34:58 volumio volumio[899]: (node:899) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 351)
Aug 28 19:34:58 volumio volumio[899]: info: Connection to go-librespot Websocket closed
Aug 28 19:35:01 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:35:01 volumio volumio[899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 28 19:35:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 28 19:35:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 747.
Aug 28 19:35:01 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 28 19:35:01 volumio systemd[1]: Started go-librespot Daemon.
Aug 28 19:35:01 volumio go-librespot[30708]: go-librespot daemon starting...
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=info msg="running go-librespot 0.7.1"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=debug msg="app state loaded"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=debug msg="stored credentials not found"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+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 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+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 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=info msg="zeroconf server listening on port 46789"
Aug 28 19:35:01 volumio go-librespot[30708]: time="2026-08-28T19:35:01+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 28 19:35:02 volumio go-librespot[30708]: time="2026-08-28T19:35:02+02:00" level=debug msg="obtained new client token: AAF9nq6qW0H5tTx7Rfz3A7DwCB3xEqBCQSSmGPd7NTLDUHtT4bqoVjmDyLzq2bt6vrzM3A8K/ewT9+xHwqRlGY/VFfxdQ9Ap8VM34A+3d0qyOJVoNJvkqbbJh3veii0mRJ8H80YPzLzy6J7GFdP0Xqv+doDEjwVjf83QEcQVjmtPBZ7d6HVYpOJyc9aq848AZKQc/zW4KZQcTJFmqWTP7c/w0PqhbZqprKzGUiQee0Cj575FIxnzZA=="
Aug 28 19:35:02 volumio go-librespot[30708]: time="2026-08-28T19:35:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Aug 28 19:35:04 volumio volumio[899]: info: Initializing connection to go-librespot Websocket
Aug 28 19:35:04 volumio go-librespot[30708]: time="2026-08-28T19:35:04+02:00" level=debug msg="new websocket client"
Aug 28 19:35:04 volumio volumio[899]: info: Connection to go-librespot Websocket established
Aug 28 19:35:05 volumio volumio[899]: info: ___________ PLUGINS: Run Shutdown Tasks ___________
Aug 28 19:35:05 volumio volumio[899]: info: PLUGIN onShutdown : networkfs
Aug 28 19:35:05 volumio volumio[899]: info: PLUGIN onShutdown : audiophonicsonoff
Aug 28 19:35:05 volumio volumio[899]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 28 19:35:05 volumio volumio[899]: TypeError: Cannot read property 'writeSync' of undefined
Aug 28 19:35:05 volumio volumio[899]: at ControllerAudiophonicsOnOff.onVolumioShutdown (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25)
Aug 28 19:35:05 volumio volumio[899]: at PluginManager.onVolumioShutdownPlugin (/volumio/app/pluginmanager.js:638:30)
Aug 28 19:35:05 volumio volumio[899]: at HashMap. (/volumio/app/pluginmanager.js:621:31)
Aug 28 19:35:05 volumio volumio[899]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Aug 28 19:35:05 volumio volumio[899]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Aug 28 19:35:05 volumio volumio[899]: at PluginManager.onVolumioShutdown (/volumio/app/pluginmanager.js:619:20)
Aug 28 19:35:05 volumio volumio[899]: at CoreCommandRouter.shutdown (/volumio/app/index.js:1328:22)
Aug 28 19:35:05 volumio volumio[899]: at ControllerAudiophonicsOnOff.hardShutdownRequest (/data/plugins/system_hardware/audiophonicsonoff/index.js:209:21)
Aug 28 19:35:05 volumio volumio[899]: at /data/plugins/system_hardware/audiophonicsonoff/node_modules/onoff/onoff.js:135:9
Aug 28 19:35:05 volumio volumio[899]: at Array.forEach ()
Aug 28 19:35:05 volumio volumio[899]: at pollerEventHandler (/data/plugins/system_hardware/audiophonicsonoff/node_modules/onoff/onoff.js:134:32)
Aug 28 19:35:05 volumio volumio[899]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 28 19:35:05 volumio sudo[30735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-28 19:34
Aug 28 19:35:05 volumio sudo[30735]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET"
VOLUMIO_VERSION="3.912"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"