-- Logs begin at Fri 2025-12-12 20:25:14 CET, end at Fri 2025-12-12 20:53:44 CET. -- Dec 12 20:52:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87312. Dec 12 20:52:00 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:00 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:00 volumio go-librespot[21523]: Librespot-go daemon starting... Dec 12 20:52:00 volumio go-librespot[21523]: time="2025-12-12T20:52:00+01:00" level=info msg="generated new device id: 200059947ee52f397769936d779312505b102da8" Dec 12 20:52:00 volumio go-librespot[21523]: time="2025-12-12T20:52:00+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:00 volumio volumio[16068]: info: Dec 12 20:52:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:00 volumio volumio[16068]: info: ------------------------------ 1115ms Dec 12 20:52:00 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:00 volumio go-librespot[21523]: time="2025-12-12T20:52:00+01:00" level=debug msg="new websocket client" Dec 12 20:52:00 volumio volumio[16068]: info: ------------------------------ 1132ms Dec 12 20:52:00 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:00 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:00 volumio volumio[16068]: info: Dec 12 20:52:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:00 volumio volumio[16068]: info: ------------------------------ 1361ms Dec 12 20:52:00 volumio go-librespot[21523]: time="2025-12-12T20:52:00+01:00" level=debug msg="obtained new client token: AACA2r1VxpJXppVthIZEzn2SEIeFB0ttQw3vlbJCPR6xONnPpLFOfEQLRtXxxJ25YOR6gPe5mB30WyfnyXvzl97FVnLiKAfs/V/LPney+vgDHBYXcqSsBay/9PN6u1c4CVQakwUN5dhxr8ze6c+/D98eCnBEm0zWi/3hLPfVeHxWpbwhcE1wwu/3sw34hwt6IDpDcs2W6kcGNiGXnbpVT2YBhd7eoeNWXu0ohsWjEY5JsBidXWUN4Nrs3qUDML+F" Dec 12 20:52:00 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:00 volumio volumio[16068]: info: ------------------------------ 1270ms Dec 12 20:52:00 volumio go-librespot[21523]: time="2025-12-12T20:52:00+01: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]" Dec 12 20:52:01 volumio go-librespot[21523]: time="2025-12-12T20:52:01+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:01 volumio volumio[16068]: info: ------------------------------ 1557ms Dec 12 20:52:01 volumio volumio[16068]: info: Dec 12 20:52:01 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:01 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:01 volumio volumio[16068]: info: ------------------------------ 1800ms Dec 12 20:52:01 volumio volumio[16068]: info: ------------------------------ 1917ms Dec 12 20:52:01 volumio go-librespot[21523]: time="2025-12-12T20:52:01+01:00" level=debug msg="completed challenge" Dec 12 20:52:01 volumio go-librespot[21523]: time="2025-12-12T20:52:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:01 volumio volumio[16068]: info: Dec 12 20:52:01 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:01 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:01 volumio volumio[16068]: info: ------------------------------ 2100ms Dec 12 20:52:01 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:01 volumio volumio[16068]: info: ------------------------------ 1973ms Dec 12 20:52:02 volumio volumio[16068]: info: ------------------------------ 2309ms Dec 12 20:52:02 volumio volumio[16068]: info: ------------------------------ 2353ms Dec 12 20:52:02 volumio volumio[16068]: info: ------------------------------ 2074ms Dec 12 20:52:02 volumio volumio[16068]: info: ------------------------------ 1510ms Dec 12 20:52:03 volumio volumio[16068]: info: ------------------------------ 1311ms Dec 12 20:52:03 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:03 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:03 volumio volumio[16068]: info: Consume mode Dec 12 20:52:03 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:03 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:03 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:03 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:03 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:03 volumio volumio[16068]: (node:16068) 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: 23240) Dec 12 20:52:03 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:03 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:03 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: ------------------------------ 364ms Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:03 volumio volumio[16068]: info: Dec 12 20:52:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: ------------------------------ 597ms Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: ------------------------------ 785ms Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: ------------------------------ 938ms Dec 12 20:52:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87313. Dec 12 20:52:04 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:04 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:04 volumio go-librespot[21553]: Librespot-go daemon starting... Dec 12 20:52:04 volumio volumio[16068]: info: Dec 12 20:52:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:04 volumio volumio[16068]: info: ------------------------------ 1200ms Dec 12 20:52:04 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:04 volumio go-librespot[21553]: time="2025-12-12T20:52:04+01:00" level=info msg="generated new device id: 5e22fbf8e203857fe48a94d7febc82f3c6f75a0b" Dec 12 20:52:04 volumio go-librespot[21553]: time="2025-12-12T20:52:04+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:04 volumio go-librespot[21553]: time="2025-12-12T20:52:04+01:00" level=debug msg="new websocket client" Dec 12 20:52:04 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:05 volumio volumio[16068]: info: ------------------------------ 1134ms Dec 12 20:52:05 volumio go-librespot[21553]: time="2025-12-12T20:52:05+01:00" level=debug msg="obtained new client token: AAC9RtymzfZviNbZT1G6u8KW6R/tvL1newpBiRVli/r9wA+uavOwA5bzmT/R2uBEf8KH2QxY3VC2Zs0BA1HW49kI2/ZUAfoRDdCTmlT13V9DdV2fOkXMu6ATC5T5/soN+DuApiosbxmPUq1l5nnLzs0tRzSvrt2ZMGfbZgkCqBTyQKUVhl34B1VOXEzcfKuxUWpgcMrcjpjeUNRjtL569GuyEvwDmfWQGFXIXhlqtjpstWplMVhWMX0pX4dAgg==" Dec 12 20:52:05 volumio volumio[16068]: info: Dec 12 20:52:05 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:05 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:05 volumio volumio[16068]: info: ------------------------------ 1324ms Dec 12 20:52:05 volumio volumio[16068]: info: ------------------------------ 1315ms Dec 12 20:52:05 volumio go-librespot[21553]: time="2025-12-12T20:52:05+01: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]" Dec 12 20:52:05 volumio volumio[16068]: info: Dec 12 20:52:05 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:05 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:05 volumio volumio[16068]: info: ------------------------------ 1521ms Dec 12 20:52:05 volumio go-librespot[21553]: time="2025-12-12T20:52:05+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:05 volumio volumio[16068]: info: ------------------------------ 1663ms Dec 12 20:52:06 volumio volumio[16068]: info: ------------------------------ 1844ms Dec 12 20:52:06 volumio go-librespot[21553]: time="2025-12-12T20:52:06+01:00" level=debug msg="completed challenge" Dec 12 20:52:06 volumio volumio[16068]: info: Dec 12 20:52:06 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:06 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:06 volumio volumio[16068]: info: ------------------------------ 2018ms Dec 12 20:52:06 volumio go-librespot[21553]: time="2025-12-12T20:52:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:06 volumio volumio[16068]: info: ------------------------------ 2156ms Dec 12 20:52:06 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:06 volumio volumio[16068]: info: ------------------------------ 2345ms Dec 12 20:52:06 volumio volumio[16068]: info: ------------------------------ 2128ms Dec 12 20:52:07 volumio volumio[16068]: info: ------------------------------ 2063ms Dec 12 20:52:07 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:07 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:07 volumio volumio[16068]: info: Consume mode Dec 12 20:52:07 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:07 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:07 volumio volumio[16068]: info: ------------------------------ 1911ms Dec 12 20:52:07 volumio volumio[16068]: info: ------------------------------ 1421ms Dec 12 20:52:07 volumio volumio[16068]: info: Dec 12 20:52:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:07 volumio volumio[16068]: info: Dec 12 20:52:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:07 volumio volumio[16068]: info: Dec 12 20:52:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:07 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:07 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:07 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:07 volumio volumio[16068]: (node:16068) 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: 23241) Dec 12 20:52:07 volumio volumio[16068]: info: Dec 12 20:52:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:07 volumio volumio[16068]: info: Dec 12 20:52:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:07 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:08 volumio volumio[16068]: info: ------------------------------ 258ms Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: ------------------------------ 457ms Dec 12 20:52:08 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: ------------------------------ 755ms Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: ------------------------------ 911ms Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:08 volumio volumio[16068]: info: Dec 12 20:52:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:09 volumio volumio[16068]: info: Dec 12 20:52:09 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:09 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:09 volumio volumio[16068]: info: ------------------------------ 1094ms Dec 12 20:52:09 volumio volumio[16068]: info: ------------------------------ 1073ms Dec 12 20:52:09 volumio volumio[16068]: info: Dec 12 20:52:09 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:09 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:09 volumio volumio[16068]: info: ------------------------------ 1263ms Dec 12 20:52:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87314. Dec 12 20:52:09 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:09 volumio volumio[16068]: info: ------------------------------ 1271ms Dec 12 20:52:09 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:09 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:09 volumio go-librespot[21568]: Librespot-go daemon starting... Dec 12 20:52:09 volumio go-librespot[21568]: time="2025-12-12T20:52:09+01:00" level=info msg="generated new device id: f635c3b00b49d4d678d9365ed13eb654210dd6c1" Dec 12 20:52:09 volumio go-librespot[21568]: time="2025-12-12T20:52:09+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:09 volumio go-librespot[21568]: time="2025-12-12T20:52:09+01:00" level=debug msg="new websocket client" Dec 12 20:52:10 volumio volumio[16068]: info: ------------------------------ 1713ms Dec 12 20:52:10 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:10 volumio go-librespot[21568]: time="2025-12-12T20:52:10+01:00" level=debug msg="obtained new client token: AADYQOnqX/Ui6ZLTM9/FQLzFZaHhTgh+vDL433ZmX2Jw9cdOjd3lto3Rb/UPdOmRG2gNqcqcZsB4Uu5qj0lcKelpk75jkHXVZP/2umAkiK5KYXPLJhCZXxd/Na/VNkIZvqirnSrGtOEgG3tptmIwyJMj+xyYF4ED1usg+iVRVgBX4GOVFCNyICENV3+1pXDueyUBTdmC4esRJzMTY8FlKcMMalqBVrKuF3yQXqdKUQzfLtfogZTfN1hlJdx9pQ==" Dec 12 20:52:10 volumio volumio[16068]: info: Dec 12 20:52:10 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:10 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:10 volumio volumio[16068]: info: ------------------------------ 1722ms Dec 12 20:52:10 volumio go-librespot[21568]: time="2025-12-12T20:52:10+01: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]" Dec 12 20:52:10 volumio volumio[16068]: info: ------------------------------ 1854ms Dec 12 20:52:10 volumio go-librespot[21568]: time="2025-12-12T20:52:10+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:10 volumio volumio[16068]: info: Dec 12 20:52:10 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:10 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:10 volumio volumio[16068]: info: ------------------------------ 2043ms Dec 12 20:52:10 volumio volumio[16068]: info: ------------------------------ 2072ms Dec 12 20:52:11 volumio go-librespot[21568]: time="2025-12-12T20:52:11+01:00" level=debug msg="completed challenge" Dec 12 20:52:11 volumio volumio[16068]: info: ------------------------------ 2357ms Dec 12 20:52:11 volumio go-librespot[21568]: time="2025-12-12T20:52:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:11 volumio volumio[16068]: info: ------------------------------ 2383ms Dec 12 20:52:11 volumio volumio[16068]: info: ------------------------------ 2187ms Dec 12 20:52:11 volumio volumio[16068]: info: ------------------------------ 1450ms Dec 12 20:52:11 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:11 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:11 volumio volumio[16068]: info: Consume mode Dec 12 20:52:11 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:11 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:11 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:11 volumio volumio[16068]: info: ------------------------------ 1244ms Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: ------------------------------ 326ms Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: ------------------------------ 523ms Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: Dec 12 20:52:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:12 volumio volumio[16068]: info: ------------------------------ 708ms Dec 12 20:52:13 volumio volumio[16068]: info: ------------------------------ 817ms Dec 12 20:52:13 volumio volumio[16068]: info: Dec 12 20:52:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:13 volumio volumio[16068]: info: Dec 12 20:52:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:13 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:13 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:13 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:13 volumio volumio[16068]: (node:16068) 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: 23242) Dec 12 20:52:13 volumio volumio[16068]: info: Dec 12 20:52:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:13 volumio volumio[16068]: info: Dec 12 20:52:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:13 volumio volumio[16068]: info: Dec 12 20:52:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:13 volumio volumio[16068]: info: ------------------------------ 1045ms Dec 12 20:52:13 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:13 volumio volumio[16068]: info: ------------------------------ 1155ms Dec 12 20:52:13 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:13 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:14 volumio volumio[16068]: info: Dec 12 20:52:14 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:14 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:14 volumio volumio[16068]: info: ------------------------------ 1376ms Dec 12 20:52:14 volumio volumio[16068]: info: ------------------------------ 1369ms Dec 12 20:52:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87315. Dec 12 20:52:14 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:14 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:14 volumio go-librespot[21638]: Librespot-go daemon starting... Dec 12 20:52:14 volumio go-librespot[21638]: time="2025-12-12T20:52:14+01:00" level=info msg="generated new device id: 976c9e55df9c8996b9f2dce8103188115360c8f8" Dec 12 20:52:14 volumio go-librespot[21638]: time="2025-12-12T20:52:14+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:14 volumio volumio[16068]: info: ------------------------------ 1622ms Dec 12 20:52:14 volumio volumio[16068]: info: Dec 12 20:52:14 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:14 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:14 volumio volumio[16068]: info: ------------------------------ 1657ms Dec 12 20:52:14 volumio go-librespot[21638]: time="2025-12-12T20:52:14+01:00" level=debug msg="obtained new client token: AABadcBkiaSvKx6d/Lh0ciuNjoPMGl+saq02sJ/49pE1MaLrC8ZVp4LapzklZERQWfx6Zh0YA5qhBppH7ZGGO1XbDXm2bJA48WBR7G90B1g9A4s9ITMBqCQ0yy177Nef/8XXcrYvxeXQGhfllkuy6HAqxFKoDQs6fHLk87oSIzTurx0dbCCcmd7E8Oe6o4bCKhWGrSmP5/TIQ22uQGrRiT71v9b72hBb8xheXDtjFSuuBPOLQFqK2EpvRQnB19t1" Dec 12 20:52:14 volumio volumio[16068]: info: ------------------------------ 1730ms Dec 12 20:52:14 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:15 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:15 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:15 volumio volumio[16068]: info: Consume mode Dec 12 20:52:15 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:15 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:15 volumio go-librespot[21638]: time="2025-12-12T20:52:15+01:00" level=debug msg="new websocket client" Dec 12 20:52:15 volumio go-librespot[21638]: time="2025-12-12T20:52:15+01: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]" Dec 12 20:52:15 volumio go-librespot[21638]: time="2025-12-12T20:52:15+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:15 volumio volumio[16068]: info: Dec 12 20:52:15 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:15 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:15 volumio volumio[16068]: info: ------------------------------ 2170ms Dec 12 20:52:15 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:15 volumio volumio[16068]: info: ------------------------------ 2361ms Dec 12 20:52:15 volumio go-librespot[21638]: time="2025-12-12T20:52:15+01:00" level=debug msg="completed challenge" Dec 12 20:52:15 volumio volumio[16068]: info: ------------------------------ 2547ms Dec 12 20:52:15 volumio volumio[16068]: info: Dec 12 20:52:15 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:15 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:15 volumio volumio[16068]: info: Dec 12 20:52:15 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:15 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:15 volumio go-librespot[21638]: time="2025-12-12T20:52:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:15 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:16 volumio volumio[16068]: info: ------------------------------ 2610ms Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: ------------------------------ 2227ms Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: ------------------------------ 1881ms Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: ------------------------------ 1385ms Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: Dec 12 20:52:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:16 volumio volumio[16068]: info: ------------------------------ 1149ms Dec 12 20:52:17 volumio volumio[16068]: info: Dec 12 20:52:17 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:17 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:17 volumio volumio[16068]: info: ------------------------------ 1344ms Dec 12 20:52:17 volumio volumio[16068]: info: ------------------------------ 1340ms Dec 12 20:52:17 volumio volumio[16068]: info: Dec 12 20:52:17 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:17 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:17 volumio volumio[16068]: info: ------------------------------ 1626ms Dec 12 20:52:17 volumio volumio[16068]: info: ------------------------------ 1633ms Dec 12 20:52:18 volumio volumio[16068]: info: Dec 12 20:52:18 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:18 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:18 volumio volumio[16068]: info: ------------------------------ 1821ms Dec 12 20:52:18 volumio volumio[16068]: info: ------------------------------ 1731ms Dec 12 20:52:18 volumio volumio[16068]: info: Dec 12 20:52:18 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:18 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:18 volumio volumio[16068]: info: ------------------------------ 1928ms Dec 12 20:52:18 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:18 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:18 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:18 volumio volumio[16068]: (node:16068) 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: 23243) Dec 12 20:52:18 volumio volumio[16068]: info: ------------------------------ 1977ms Dec 12 20:52:18 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:18 volumio volumio[16068]: info: ------------------------------ 2209ms Dec 12 20:52:18 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87316. Dec 12 20:52:19 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:19 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:19 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:19 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:19 volumio go-librespot[21653]: Librespot-go daemon starting... Dec 12 20:52:19 volumio go-librespot[21653]: time="2025-12-12T20:52:19+01:00" level=info msg="generated new device id: 42d90e0ce19c03f86e14561393d19323ff9412b7" Dec 12 20:52:19 volumio go-librespot[21653]: time="2025-12-12T20:52:19+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:19 volumio volumio[16068]: info: Dec 12 20:52:19 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:19 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:19 volumio volumio[16068]: info: ------------------------------ 2435ms Dec 12 20:52:19 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:19 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:19 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:19 volumio volumio[16068]: info: Consume mode Dec 12 20:52:19 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:19 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:19 volumio volumio[16068]: info: ------------------------------ 2587ms Dec 12 20:52:19 volumio go-librespot[21653]: time="2025-12-12T20:52:19+01:00" level=debug msg="obtained new client token: AAA0BCFS/FB/2kup6Pc8UFE3nO8f3EZah0XmRXQFyphljYL9ehRf++NW7lfbSEV8lB+MhbbtsKrDm5HNR60v2D592+VaxW4fx9YKc88RpsVHSDWemxrVsCLbmV79Xu5SefVDhtWN0KevdD3/mGAKda0l/XM175UNJBLHS//cOahherHnX6przqQHNfuI6isuQ5vNRTk1TEgEPdAVmOBHzb1HENYoD4gcGridNvaZ5XVGy7rMkio7OeSmLbyEMrfP" Dec 12 20:52:19 volumio volumio[16068]: info: ------------------------------ 2809ms Dec 12 20:52:19 volumio volumio[16068]: info: ------------------------------ 2648ms Dec 12 20:52:19 volumio go-librespot[21653]: time="2025-12-12T20:52:19+01: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]" Dec 12 20:52:19 volumio volumio[16068]: info: Dec 12 20:52:19 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:19 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:19 volumio volumio[16068]: info: Dec 12 20:52:19 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:19 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:20 volumio go-librespot[21653]: time="2025-12-12T20:52:20+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:20 volumio volumio[16068]: info: ------------------------------ 2409ms Dec 12 20:52:20 volumio volumio[16068]: info: Dec 12 20:52:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:20 volumio volumio[16068]: info: Dec 12 20:52:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:20 volumio volumio[16068]: info: ------------------------------ 2422ms Dec 12 20:52:20 volumio go-librespot[21653]: time="2025-12-12T20:52:20+01:00" level=debug msg="completed challenge" Dec 12 20:52:20 volumio go-librespot[21653]: time="2025-12-12T20:52:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:20 volumio volumio[16068]: info: ------------------------------ 2273ms Dec 12 20:52:20 volumio volumio[16068]: info: Dec 12 20:52:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:20 volumio volumio[16068]: info: ------------------------------ 1731ms Dec 12 20:52:20 volumio volumio[16068]: info: Dec 12 20:52:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:20 volumio volumio[16068]: info: Dec 12 20:52:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: ------------------------------ 1266ms Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: ------------------------------ 1446ms Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: Dec 12 20:52:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:21 volumio volumio[16068]: info: ------------------------------ 1449ms Dec 12 20:52:21 volumio volumio[16068]: info: ------------------------------ 1641ms Dec 12 20:52:22 volumio volumio[16068]: info: Dec 12 20:52:22 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:22 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:22 volumio volumio[16068]: info: ------------------------------ 1109ms Dec 12 20:52:22 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:22 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:22 volumio volumio[16068]: info: ------------------------------ 1250ms Dec 12 20:52:22 volumio volumio[16068]: info: Dec 12 20:52:22 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:22 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:22 volumio volumio[16068]: info: ------------------------------ 1453ms Dec 12 20:52:22 volumio volumio[16068]: info: ------------------------------ 1511ms Dec 12 20:52:22 volumio volumio[16068]: info: Dec 12 20:52:22 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:22 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:22 volumio volumio[16068]: info: ------------------------------ 1745ms Dec 12 20:52:23 volumio volumio[16068]: info: ------------------------------ 1782ms Dec 12 20:52:23 volumio volumio[16068]: info: ------------------------------ 1954ms Dec 12 20:52:23 volumio volumio[16068]: info: Dec 12 20:52:23 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:23 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:23 volumio volumio[16068]: info: ------------------------------ 2172ms Dec 12 20:52:23 volumio volumio[16068]: info: ------------------------------ 2287ms Dec 12 20:52:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87317. Dec 12 20:52:23 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:23 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:23 volumio go-librespot[21684]: Librespot-go daemon starting... Dec 12 20:52:23 volumio go-librespot[21684]: time="2025-12-12T20:52:23+01:00" level=info msg="generated new device id: 0bf8df9cae7cee8dfa4f3789c900519ee2ac49e4" Dec 12 20:52:23 volumio volumio[16068]: info: ------------------------------ 2548ms Dec 12 20:52:23 volumio go-librespot[21684]: time="2025-12-12T20:52:23+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:24 volumio volumio[16068]: info: ------------------------------ 2119ms Dec 12 20:52:24 volumio volumio[16068]: info: ------------------------------ 1908ms Dec 12 20:52:24 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:24 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:24 volumio volumio[16068]: info: Consume mode Dec 12 20:52:24 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:24 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:24 volumio go-librespot[21684]: time="2025-12-12T20:52:24+01:00" level=debug msg="obtained new client token: AAB6xbHiR0jH2Sui31UnhznQQBHTbhOhV+MI0obWGZtp9s50iOHrma3zHV7qP6vx5mGoz2fFyoEJWOKUAtWQYdHHfLErTpDIEixEXOtG/X4gmTXcAb9VfEsci4+DaaH0IELPZELbodsGuqt1CEeW9b678/mJRoZ78x5vzWktKzG6jgfbU3yYLQeDZ80+iHEMQbL2ZQDCuqFeFD1IBKvtTs4Oy0UHIMNIEvSLgFIe7POLHn0H0heEDdHAQ+ZEKWA6" Dec 12 20:52:24 volumio volumio[16068]: info: ------------------------------ 1641ms Dec 12 20:52:24 volumio go-librespot[21684]: time="2025-12-12T20:52:24+01: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]" Dec 12 20:52:24 volumio volumio[16068]: info: ------------------------------ 1230ms Dec 12 20:52:24 volumio volumio[16068]: info: Dec 12 20:52:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:24 volumio volumio[16068]: info: Dec 12 20:52:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:24 volumio volumio[16068]: info: Dec 12 20:52:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:24 volumio go-librespot[21684]: time="2025-12-12T20:52:24+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:24 volumio volumio[16068]: info: Dec 12 20:52:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:24 volumio volumio[16068]: info: Dec 12 20:52:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: ------------------------------ 372ms Dec 12 20:52:25 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio go-librespot[21684]: time="2025-12-12T20:52:25+01:00" level=debug msg="completed challenge" Dec 12 20:52:25 volumio go-librespot[21684]: time="2025-12-12T20:52:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:25 volumio volumio[16068]: info: ------------------------------ 624ms Dec 12 20:52:25 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: socket hang up Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: ------------------------------ 813ms Dec 12 20:52:25 volumio volumio[16068]: info: ------------------------------ 918ms Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:25 volumio volumio[16068]: info: Dec 12 20:52:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:26 volumio volumio[16068]: info: Dec 12 20:52:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:26 volumio volumio[16068]: info: ------------------------------ 1197ms Dec 12 20:52:26 volumio volumio[16068]: info: Dec 12 20:52:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:26 volumio volumio[16068]: info: Dec 12 20:52:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:26 volumio volumio[16068]: info: ------------------------------ 1120ms Dec 12 20:52:26 volumio volumio[16068]: info: Dec 12 20:52:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:26 volumio volumio[16068]: info: ------------------------------ 1294ms Dec 12 20:52:26 volumio volumio[16068]: info: ------------------------------ 1249ms Dec 12 20:52:26 volumio volumio[16068]: info: ------------------------------ 1427ms Dec 12 20:52:27 volumio volumio[16068]: info: Dec 12 20:52:27 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:27 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:27 volumio volumio[16068]: info: ------------------------------ 1594ms Dec 12 20:52:27 volumio volumio[16068]: info: ------------------------------ 1605ms Dec 12 20:52:27 volumio volumio[16068]: info: Dec 12 20:52:27 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:27 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:27 volumio volumio[16068]: info: ------------------------------ 1789ms Dec 12 20:52:27 volumio volumio[16068]: info: ------------------------------ 1715ms Dec 12 20:52:28 volumio volumio[16068]: info: ------------------------------ 1891ms Dec 12 20:52:28 volumio volumio[16068]: info: ------------------------------ 2074ms Dec 12 20:52:28 volumio volumio[16068]: info: ------------------------------ 1891ms Dec 12 20:52:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87318. Dec 12 20:52:28 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:28 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:28 volumio go-librespot[21698]: Librespot-go daemon starting... Dec 12 20:52:28 volumio go-librespot[21698]: time="2025-12-12T20:52:28+01:00" level=info msg="generated new device id: 423562a2e1e1fa5420c89b6d3fe10b54b002580c" Dec 12 20:52:28 volumio go-librespot[21698]: time="2025-12-12T20:52:28+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:28 volumio volumio[16068]: info: ------------------------------ 1389ms Dec 12 20:52:28 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:28 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:28 volumio go-librespot[21698]: time="2025-12-12T20:52:28+01:00" level=debug msg="new websocket client" Dec 12 20:52:28 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:28 volumio volumio[16068]: info: Consume mode Dec 12 20:52:28 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:28 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:28 volumio volumio[16068]: info: ------------------------------ 1203ms Dec 12 20:52:28 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:29 volumio go-librespot[21698]: time="2025-12-12T20:52:29+01:00" level=debug msg="obtained new client token: AACcmva2Z24zPztoSPYnK7qz/g+FywoXS6E94Zsmvs+Cfgk3ICt0nZWMbnABu7JkR48uWMXlUOqtauzgx0YAcKVH4Cd5XjazFTXf7HtvCPHcDOjBpT0A4Rt+9ynBfs+KQrW9+IO8/Tr77OHnLycXoYsrwl0dLdGw+iwCBP5hZivkCnqo3OTCD/Se7pjiEIa5uTuB9Q5+CII2eNGXTevQZ9ApzfhuVTNcSmQsGqpBiWHsTHpFZoxqz5D5YIJ8Aw==" Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio go-librespot[21698]: time="2025-12-12T20:52:29+01: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]" Dec 12 20:52:29 volumio volumio[16068]: info: ------------------------------ 251ms Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio go-librespot[21698]: time="2025-12-12T20:52:29+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:29 volumio volumio[16068]: info: ------------------------------ 438ms Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: ------------------------------ 635ms Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:29 volumio volumio[16068]: info: Dec 12 20:52:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:30 volumio volumio[16068]: info: ------------------------------ 814ms Dec 12 20:52:30 volumio go-librespot[21698]: time="2025-12-12T20:52:30+01:00" level=debug msg="completed challenge" Dec 12 20:52:30 volumio go-librespot[21698]: time="2025-12-12T20:52:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:30 volumio volumio[16068]: info: Dec 12 20:52:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:30 volumio volumio[16068]: info: ------------------------------ 1030ms Dec 12 20:52:30 volumio volumio[16068]: info: Dec 12 20:52:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:30 volumio volumio[16068]: info: Dec 12 20:52:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:30 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:30 volumio volumio[16068]: info: ------------------------------ 1092ms Dec 12 20:52:30 volumio volumio[16068]: info: Dec 12 20:52:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:30 volumio volumio[16068]: info: ------------------------------ 1260ms Dec 12 20:52:30 volumio volumio[16068]: info: ------------------------------ 1092ms Dec 12 20:52:31 volumio volumio[16068]: info: ------------------------------ 1379ms Dec 12 20:52:31 volumio volumio[16068]: info: Dec 12 20:52:31 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:31 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:31 volumio volumio[16068]: info: ------------------------------ 1607ms Dec 12 20:52:31 volumio volumio[16068]: info: ------------------------------ 1705ms Dec 12 20:52:31 volumio volumio[16068]: info: Dec 12 20:52:31 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:31 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:31 volumio volumio[16068]: info: ------------------------------ 1879ms Dec 12 20:52:31 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:32 volumio volumio[16068]: info: ------------------------------ 1758ms Dec 12 20:52:32 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:32 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:32 volumio volumio[16068]: (node:16068) 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: 23244) Dec 12 20:52:32 volumio volumio[16068]: info: ------------------------------ 2019ms Dec 12 20:52:32 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:32 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:32 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:32 volumio volumio[16068]: info: Consume mode Dec 12 20:52:32 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:32 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:32 volumio volumio[16068]: info: ------------------------------ 2256ms Dec 12 20:52:32 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:32 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:32 volumio volumio[16068]: info: ------------------------------ 2040ms Dec 12 20:52:32 volumio volumio[16068]: info: ------------------------------ 1504ms Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio volumio[16068]: info: ------------------------------ 1315ms Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87319. Dec 12 20:52:33 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:33 volumio go-librespot[21728]: Librespot-go daemon starting... Dec 12 20:52:33 volumio go-librespot[21728]: time="2025-12-12T20:52:33+01:00" level=info msg="generated new device id: 22a409baf87dee3d3a6ac8753a946a60a7dab551" Dec 12 20:52:33 volumio go-librespot[21728]: time="2025-12-12T20:52:33+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:33 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:33 volumio volumio[16068]: info: ------------------------------ 482ms Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio go-librespot[21728]: time="2025-12-12T20:52:33+01:00" level=debug msg="new websocket client" Dec 12 20:52:33 volumio go-librespot[21728]: time="2025-12-12T20:52:33+01:00" level=debug msg="obtained new client token: AABCMF6TQHhUTlF/sjt6qgiP2kwrN1I2w0nN/Czy4wUpl0iVeX8BrQmCTKoKDT7GdQmad8F+cpMqjukG0uL94i+gPwiX0B9cHYvKpXG3stclFIyGQkAJN/fydaVaUoJdFXpbvSNfpCMjFu5R/mBCwJEF9bdDGN4B0gpYyamjgsRBtbZGIXc0PIo5Gfkxd34bCYet52uRLxds3QYmxyU9bG69GMnPpme78ugKUvXp6wQH7qv7ZCmG9z78vICfmYOt" Dec 12 20:52:33 volumio volumio[16068]: info: ------------------------------ 740ms Dec 12 20:52:33 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:33 volumio volumio[16068]: info: Dec 12 20:52:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio go-librespot[21728]: time="2025-12-12T20:52:34+01: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]" Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio volumio[16068]: info: ------------------------------ 930ms Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio go-librespot[21728]: time="2025-12-12T20:52:34+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:34 volumio volumio[16068]: info: ------------------------------ 1027ms Dec 12 20:52:34 volumio volumio[16068]: info: Dec 12 20:52:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:34 volumio volumio[16068]: info: ------------------------------ 1268ms Dec 12 20:52:34 volumio go-librespot[21728]: time="2025-12-12T20:52:34+01:00" level=debug msg="completed challenge" Dec 12 20:52:34 volumio volumio[16068]: info: ------------------------------ 1157ms Dec 12 20:52:34 volumio go-librespot[21728]: time="2025-12-12T20:52:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:35 volumio volumio[16068]: info: Dec 12 20:52:35 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:35 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:35 volumio volumio[16068]: info: ------------------------------ 1360ms Dec 12 20:52:35 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:35 volumio volumio[16068]: info: ------------------------------ 1295ms Dec 12 20:52:35 volumio volumio[16068]: info: Dec 12 20:52:35 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:35 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:35 volumio volumio[16068]: info: ------------------------------ 1483ms Dec 12 20:52:35 volumio volumio[16068]: info: ------------------------------ 1529ms Dec 12 20:52:35 volumio volumio[16068]: info: ------------------------------ 1789ms Dec 12 20:52:36 volumio volumio[16068]: info: Dec 12 20:52:36 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:36 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:36 volumio volumio[16068]: info: ------------------------------ 1985ms Dec 12 20:52:36 volumio volumio[16068]: info: ------------------------------ 2095ms Dec 12 20:52:36 volumio volumio[16068]: info: ------------------------------ 2277ms Dec 12 20:52:36 volumio volumio[16068]: info: ------------------------------ 2087ms Dec 12 20:52:36 volumio volumio[16068]: info: ------------------------------ 1876ms Dec 12 20:52:36 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:52:36 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:36 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:52:36 volumio volumio[16068]: (node:16068) 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: 23245) Dec 12 20:52:37 volumio volumio[16068]: info: ------------------------------ 1733ms Dec 12 20:52:37 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:52:37 volumio volumio[16068]: info: ------------------------------ 1240ms Dec 12 20:52:37 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:37 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:37 volumio volumio[16068]: info: Consume mode Dec 12 20:52:37 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:37 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:37 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:37 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:52:37 volumio volumio[16068]: info: Dec 12 20:52:37 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:37 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:37 volumio volumio[16068]: info: Dec 12 20:52:37 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:37 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:37 volumio volumio[16068]: info: Dec 12 20:52:37 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:37 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:37 volumio volumio[16068]: info: Dec 12 20:52:37 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:37 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:37 volumio volumio[16068]: info: Dec 12 20:52:37 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:37 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87320. Dec 12 20:52:38 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:38 volumio volumio[16068]: info: ------------------------------ 239ms Dec 12 20:52:38 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:38 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:38 volumio go-librespot[21745]: Librespot-go daemon starting... Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio go-librespot[21745]: time="2025-12-12T20:52:38+01:00" level=info msg="generated new device id: d71f236aae566c67899f2c4763903ff868dad88b" Dec 12 20:52:38 volumio go-librespot[21745]: time="2025-12-12T20:52:38+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:38 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:38 volumio volumio[16068]: info: ------------------------------ 443ms Dec 12 20:52:38 volumio go-librespot[21745]: time="2025-12-12T20:52:38+01:00" level=debug msg="obtained new client token: AADR/XXO9oE8k1fLPrlv5cZTU7YJ3+7FkMZjvQebQU/xcLsLH+gDdzOOi3XMwSyHsGApHqC9/BNB/b3iO3WZtHVM2iYQGCemPd2kO6onHZPEyzMIPL3DYfs1zTSzN62XqvPS+qB0NeCZfhoevpoOebYhY3IZyWT/ipHAHPCCGXcmBBYcLc1P5GAmZpbbBPZHcT16KM2Xz4CS4c1ux49xupBsx+2Izi2JXZbreYAy6SNARqohij8JTZafwWwWQWqK" Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio volumio[16068]: info: ------------------------------ 695ms Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio volumio[16068]: info: Dec 12 20:52:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:38 volumio go-librespot[21745]: time="2025-12-12T20:52:38+01: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]" Dec 12 20:52:38 volumio volumio[16068]: info: ------------------------------ 895ms Dec 12 20:52:39 volumio go-librespot[21745]: time="2025-12-12T20:52:39+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:39 volumio volumio[16068]: info: Dec 12 20:52:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:39 volumio volumio[16068]: info: ------------------------------ 1079ms Dec 12 20:52:39 volumio volumio[16068]: info: Dec 12 20:52:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:39 volumio volumio[16068]: info: Dec 12 20:52:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:39 volumio volumio[16068]: info: ------------------------------ 1120ms Dec 12 20:52:39 volumio volumio[16068]: info: Dec 12 20:52:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:39 volumio volumio[16068]: info: ------------------------------ 1294ms Dec 12 20:52:39 volumio go-librespot[21745]: time="2025-12-12T20:52:39+01:00" level=debug msg="completed challenge" Dec 12 20:52:39 volumio go-librespot[21745]: time="2025-12-12T20:52:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:39 volumio volumio[16068]: info: ------------------------------ 1052ms Dec 12 20:52:39 volumio volumio[16068]: info: ------------------------------ 1296ms Dec 12 20:52:40 volumio volumio[16068]: info: Dec 12 20:52:40 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:40 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:40 volumio volumio[16068]: info: ------------------------------ 1506ms Dec 12 20:52:40 volumio volumio[16068]: info: ------------------------------ 1603ms Dec 12 20:52:40 volumio volumio[16068]: info: Dec 12 20:52:40 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:40 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:40 volumio volumio[16068]: info: ------------------------------ 1789ms Dec 12 20:52:40 volumio volumio[16068]: info: ------------------------------ 1658ms Dec 12 20:52:40 volumio volumio[16068]: info: ------------------------------ 1934ms Dec 12 20:52:41 volumio volumio[16068]: info: ------------------------------ 2110ms Dec 12 20:52:41 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:41 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:41 volumio volumio[16068]: info: Consume mode Dec 12 20:52:41 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:41 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:41 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:41 volumio volumio[16068]: info: ------------------------------ 1916ms Dec 12 20:52:41 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:41 volumio volumio[16068]: info: ------------------------------ 1458ms Dec 12 20:52:41 volumio volumio[16068]: info: ------------------------------ 1249ms Dec 12 20:52:41 volumio volumio[16068]: info: Dec 12 20:52:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:41 volumio volumio[16068]: info: Dec 12 20:52:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:41 volumio volumio[16068]: info: Dec 12 20:52:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:41 volumio volumio[16068]: info: Dec 12 20:52:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:41 volumio volumio[16068]: info: Dec 12 20:52:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: ------------------------------ 349ms Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: ------------------------------ 527ms Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: ------------------------------ 718ms Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: ------------------------------ 862ms Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87321. Dec 12 20:52:42 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:42 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:42 volumio go-librespot[21775]: Librespot-go daemon starting... Dec 12 20:52:42 volumio go-librespot[21775]: time="2025-12-12T20:52:42+01:00" level=info msg="generated new device id: a9c4e6acfc885a95f503f4996fc187c18a84d742" Dec 12 20:52:42 volumio go-librespot[21775]: time="2025-12-12T20:52:42+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:42 volumio volumio[16068]: info: Dec 12 20:52:42 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:42 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:42 volumio volumio[16068]: info: ------------------------------ 1074ms Dec 12 20:52:43 volumio volumio[16068]: info: ------------------------------ 1023ms Dec 12 20:52:43 volumio go-librespot[21775]: time="2025-12-12T20:52:43+01:00" level=debug msg="obtained new client token: AAA7o+5GHf953rSDu/oNN6ArIM/7ZEmFKShgL0iXpYzxfgVtSdxWZwe4Ci0n5G/sZ7mATVDJxyQcHd/tNwkxsAdU2uOx8txQxFMKA4wAqBET8lBXYyXL6XengKeoPU5jwY3e8Nl/Eq88zYgtB11bpRGYjC491SuW4gx0MkDTmfOmDtp3nC4JdA+xTfNFyL+HukqEuupxQYtR8QhWaxw7wYprNQlPeNFLKIE0SLQbL0mLp0d0D2bljAt4Ln2V1g==" Dec 12 20:52:43 volumio volumio[16068]: info: Dec 12 20:52:43 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:43 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:43 volumio volumio[16068]: info: ------------------------------ 1272ms Dec 12 20:52:43 volumio go-librespot[21775]: time="2025-12-12T20:52:43+01: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]" Dec 12 20:52:43 volumio volumio[16068]: info: ------------------------------ 1177ms Dec 12 20:52:43 volumio go-librespot[21775]: time="2025-12-12T20:52:43+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:43 volumio volumio[16068]: info: ------------------------------ 1368ms Dec 12 20:52:44 volumio volumio[16068]: info: Dec 12 20:52:44 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:44 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:44 volumio volumio[16068]: info: ------------------------------ 1565ms Dec 12 20:52:44 volumio volumio[16068]: info: ------------------------------ 1687ms Dec 12 20:52:44 volumio go-librespot[21775]: time="2025-12-12T20:52:44+01:00" level=debug msg="completed challenge" Dec 12 20:52:44 volumio go-librespot[21775]: time="2025-12-12T20:52:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:44 volumio volumio[16068]: info: Dec 12 20:52:44 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:44 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:44 volumio volumio[16068]: info: ------------------------------ 1968ms Dec 12 20:52:44 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:44 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:44 volumio volumio[16068]: info: ------------------------------ 2085ms Dec 12 20:52:44 volumio volumio[16068]: info: ------------------------------ 2269ms Dec 12 20:52:45 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:45 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:45 volumio volumio[16068]: info: Consume mode Dec 12 20:52:45 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:45 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:45 volumio volumio[16068]: info: ------------------------------ 2242ms Dec 12 20:52:45 volumio volumio[16068]: info: ------------------------------ 1912ms Dec 12 20:52:45 volumio volumio[16068]: info: ------------------------------ 1472ms Dec 12 20:52:45 volumio volumio[16068]: info: Dec 12 20:52:45 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:45 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:45 volumio volumio[16068]: info: Dec 12 20:52:45 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:45 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:45 volumio volumio[16068]: info: Dec 12 20:52:45 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:45 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:45 volumio volumio[16068]: info: ------------------------------ 1287ms Dec 12 20:52:46 volumio volumio[16068]: info: ------------------------------ 464ms Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: ------------------------------ 649ms Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: ------------------------------ 596ms Dec 12 20:52:46 volumio volumio[16068]: info: ------------------------------ 561ms Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: ------------------------------ 893ms Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:46 volumio volumio[16068]: info: Dec 12 20:52:46 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:46 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:47 volumio volumio[16068]: info: ------------------------------ 899ms Dec 12 20:52:47 volumio volumio[16068]: info: Dec 12 20:52:47 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:47 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:47 volumio volumio[16068]: info: Dec 12 20:52:47 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:47 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:47 volumio volumio[16068]: info: ------------------------------ 1089ms Dec 12 20:52:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87322. Dec 12 20:52:47 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:47 volumio volumio[16068]: info: Dec 12 20:52:47 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:47 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:47 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:47 volumio volumio[16068]: info: ------------------------------ 1129ms Dec 12 20:52:47 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:47 volumio go-librespot[21790]: Librespot-go daemon starting... Dec 12 20:52:47 volumio go-librespot[21790]: time="2025-12-12T20:52:47+01:00" level=info msg="generated new device id: d114c6352be03ddbf59246d7a26bc61594926dc0" Dec 12 20:52:47 volumio go-librespot[21790]: time="2025-12-12T20:52:47+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:47 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:47 volumio volumio[16068]: info: ------------------------------ 1125ms Dec 12 20:52:48 volumio go-librespot[21790]: time="2025-12-12T20:52:48+01:00" level=debug msg="obtained new client token: AABo9mx65if2jQpsoVah+w/JDdIYCvEyu8qfblEP+n3UG62a/U32EPkT4Mcd5YQ/WXkx4yT4KHj7E8eIGnNQy2MMYo/BnHgVLwi++fzcVevIfwLnoWo/g305EQBbWlSZt2bDCaxsYDjz73L9YC6ItKACzwvc6sxQM0KpOB8WdctH7V/ieLSpzbZ8HFo6DiZe9pUwKS7VpxEZ5lQ23xpRL+FfkgJyJo1smx5hisdoNE0PaX4hmgM1/iO3pA+BDg==" Dec 12 20:52:48 volumio volumio[16068]: info: Dec 12 20:52:48 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:48 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:48 volumio volumio[16068]: info: ------------------------------ 1443ms Dec 12 20:52:48 volumio volumio[16068]: info: ------------------------------ 1331ms Dec 12 20:52:48 volumio go-librespot[21790]: time="2025-12-12T20:52:48+01: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]" Dec 12 20:52:48 volumio volumio[16068]: info: ------------------------------ 1486ms Dec 12 20:52:48 volumio go-librespot[21790]: time="2025-12-12T20:52:48+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:48 volumio volumio[16068]: info: Dec 12 20:52:48 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:48 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:48 volumio volumio[16068]: info: ------------------------------ 1673ms Dec 12 20:52:48 volumio volumio[16068]: info: ------------------------------ 1684ms Dec 12 20:52:49 volumio volumio[16068]: info: ------------------------------ 1934ms Dec 12 20:52:49 volumio go-librespot[21790]: time="2025-12-12T20:52:49+01:00" level=debug msg="completed challenge" Dec 12 20:52:49 volumio go-librespot[21790]: time="2025-12-12T20:52:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:49 volumio volumio[16068]: info: ------------------------------ 1955ms Dec 12 20:52:49 volumio volumio[16068]: info: ------------------------------ 1670ms Dec 12 20:52:49 volumio volumio[16068]: info: ------------------------------ 1251ms Dec 12 20:52:49 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:49 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:49 volumio volumio[16068]: info: Consume mode Dec 12 20:52:49 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:49 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: ------------------------------ 250ms Dec 12 20:52:50 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: ------------------------------ 492ms Dec 12 20:52:50 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:50 volumio volumio[16068]: info: Dec 12 20:52:50 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:50 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: ------------------------------ 695ms Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: ------------------------------ 826ms Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: ------------------------------ 1021ms Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: ------------------------------ 1018ms Dec 12 20:52:51 volumio volumio[16068]: info: Dec 12 20:52:51 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:51 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:51 volumio volumio[16068]: info: ------------------------------ 1198ms Dec 12 20:52:52 volumio volumio[16068]: info: ------------------------------ 1239ms Dec 12 20:52:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87323. Dec 12 20:52:52 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:52 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:52 volumio go-librespot[21819]: Librespot-go daemon starting... Dec 12 20:52:52 volumio go-librespot[21819]: time="2025-12-12T20:52:52+01:00" level=info msg="generated new device id: 8c72bc0ac335fc919417848a39ea62bb1e9d9565" Dec 12 20:52:52 volumio go-librespot[21819]: time="2025-12-12T20:52:52+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:52 volumio volumio[16068]: info: ------------------------------ 1450ms Dec 12 20:52:52 volumio volumio[16068]: info: Dec 12 20:52:52 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:52 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:52 volumio volumio[16068]: info: ------------------------------ 1500ms Dec 12 20:52:52 volumio go-librespot[21819]: time="2025-12-12T20:52:52+01:00" level=debug msg="obtained new client token: AAAlOHcygy5B6y1f5r+T01doTIXOUSxeVuEdwp1D9vpGMZmLPpOA5DONe0c1kla0VbaAAx0r5z0bVHIby0wQhjn/mFhaN7zewuNoS7KMed/ywY3VjnanODl9XG7bKI/dy1y/9PNO9/xpx+NFAIHqGUqQZCnXQL9mIGa5j67igaL9dveoztJRrq6CZSIoINOemBjJBr7OiRgJbg3tWHlTEMcEEU1221nezYcU2nAXvctJzZO1Ihst+w92HBH5l0+g" Dec 12 20:52:52 volumio volumio[16068]: info: ------------------------------ 1647ms Dec 12 20:52:53 volumio volumio[16068]: info: Dec 12 20:52:53 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:53 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:53 volumio volumio[16068]: info: ------------------------------ 1842ms Dec 12 20:52:53 volumio go-librespot[21819]: time="2025-12-12T20:52:53+01: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]" Dec 12 20:52:53 volumio volumio[16068]: info: ------------------------------ 1790ms Dec 12 20:52:53 volumio go-librespot[21819]: time="2025-12-12T20:52:53+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:53 volumio volumio[16068]: info: ------------------------------ 1991ms Dec 12 20:52:53 volumio volumio[16068]: info: ------------------------------ 2173ms Dec 12 20:52:53 volumio go-librespot[21819]: time="2025-12-12T20:52:53+01:00" level=debug msg="completed challenge" Dec 12 20:52:53 volumio volumio[16068]: info: ------------------------------ 1968ms Dec 12 20:52:53 volumio go-librespot[21819]: time="2025-12-12T20:52:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:53 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:54 volumio volumio[16068]: info: ------------------------------ 1465ms Dec 12 20:52:54 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:52:54 volumio volumio[16068]: info: ------------------------------ 1333ms Dec 12 20:52:54 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:54 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:54 volumio volumio[16068]: info: Consume mode Dec 12 20:52:54 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:54 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:54 volumio volumio[16068]: info: Dec 12 20:52:54 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:54 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:54 volumio volumio[16068]: info: Dec 12 20:52:54 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:54 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:54 volumio volumio[16068]: info: Dec 12 20:52:54 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:54 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:54 volumio volumio[16068]: info: Dec 12 20:52:54 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:54 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:54 volumio volumio[16068]: info: Dec 12 20:52:54 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:54 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: ------------------------------ 244ms Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: ------------------------------ 417ms Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: ------------------------------ 595ms Dec 12 20:52:55 volumio volumio[16068]: info: ------------------------------ 704ms Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: ------------------------------ 989ms Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:55 volumio volumio[16068]: info: Dec 12 20:52:55 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:55 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:56 volumio volumio[16068]: info: ------------------------------ 1076ms Dec 12 20:52:56 volumio volumio[16068]: info: Dec 12 20:52:56 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:56 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:56 volumio volumio[16068]: info: ------------------------------ 1262ms Dec 12 20:52:56 volumio volumio[16068]: info: ------------------------------ 1256ms Dec 12 20:52:56 volumio volumio[16068]: info: ------------------------------ 1443ms Dec 12 20:52:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:52:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87324. Dec 12 20:52:57 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:52:57 volumio volumio[16068]: info: Dec 12 20:52:57 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:57 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:57 volumio volumio[16068]: info: ------------------------------ 1601ms Dec 12 20:52:57 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:52:57 volumio go-librespot[21833]: Librespot-go daemon starting... Dec 12 20:52:57 volumio go-librespot[21833]: time="2025-12-12T20:52:57+01:00" level=info msg="generated new device id: be305030a38e7a2c6121cde288d05ab606cfefb4" Dec 12 20:52:57 volumio go-librespot[21833]: time="2025-12-12T20:52:57+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:52:57 volumio volumio[16068]: info: ------------------------------ 1615ms Dec 12 20:52:57 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:52:57 volumio go-librespot[21833]: time="2025-12-12T20:52:57+01:00" level=debug msg="new websocket client" Dec 12 20:52:57 volumio volumio[16068]: info: Dec 12 20:52:57 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:57 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:57 volumio volumio[16068]: info: ------------------------------ 1820ms Dec 12 20:52:57 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:52:57 volumio go-librespot[21833]: time="2025-12-12T20:52:57+01:00" level=debug msg="obtained new client token: AABd2JKUEcex7xyNInk7BSRjc/VpEM7oJdjfL3J85xJIFmnGaa/TdxESpY3fZxhFYUXs4o9oZNe3rBGefC6cGQ4/5VPrJYZ6mt8/VnfslDhbuS//uKG1wzPf/+jlbmOmKLKU2G30kt7uuZgIuzQnUzbtDijPHue5yjDBbMJ2+XFoJi3QD4mtyPJTYkBBiy26tLGeM9FRrC3jHVdmTKFlceBtiE3HxtJW/aRV8EZdlvYaPdKT6UvQ0RU5F5kUnwqG" Dec 12 20:52:57 volumio volumio[16068]: info: ------------------------------ 1757ms Dec 12 20:52:57 volumio go-librespot[21833]: time="2025-12-12T20:52:57+01: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]" Dec 12 20:52:57 volumio volumio[16068]: info: ------------------------------ 1940ms Dec 12 20:52:58 volumio go-librespot[21833]: time="2025-12-12T20:52:58+01:00" level=debug msg="completed keyexchange" Dec 12 20:52:58 volumio volumio[16068]: info: ------------------------------ 2203ms Dec 12 20:52:58 volumio volumio[16068]: info: ------------------------------ 1994ms Dec 12 20:52:58 volumio go-librespot[21833]: time="2025-12-12T20:52:58+01:00" level=debug msg="completed challenge" Dec 12 20:52:58 volumio volumio[16068]: info: ------------------------------ 1502ms Dec 12 20:52:58 volumio go-librespot[21833]: time="2025-12-12T20:52:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:52:58 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:52:58 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:52:58 volumio volumio[16068]: info: Consume mode Dec 12 20:52:58 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:52:58 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:52:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:52:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:52:58 volumio volumio[16068]: info: ------------------------------ 1270ms Dec 12 20:52:58 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: ------------------------------ 246ms Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: ------------------------------ 422ms Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: ------------------------------ 683ms Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:52:59 volumio volumio[16068]: info: Dec 12 20:52:59 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:52:59 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:00 volumio volumio[16068]: info: ------------------------------ 861ms Dec 12 20:53:00 volumio volumio[16068]: info: Dec 12 20:53:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:00 volumio volumio[16068]: info: Dec 12 20:53:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:00 volumio volumio[16068]: info: Dec 12 20:53:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:00 volumio volumio[16068]: info: ------------------------------ 1054ms Dec 12 20:53:00 volumio volumio[16068]: info: ------------------------------ 1042ms Dec 12 20:53:00 volumio volumio[16068]: info: Dec 12 20:53:00 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:00 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:00 volumio volumio[16068]: info: ------------------------------ 1218ms Dec 12 20:53:00 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:53:00 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:00 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:53:00 volumio volumio[16068]: (node:16068) 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: 23246) Dec 12 20:53:00 volumio volumio[16068]: info: ------------------------------ 1080ms Dec 12 20:53:00 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:53:01 volumio volumio[16068]: info: ------------------------------ 1350ms Dec 12 20:53:01 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:01 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:01 volumio volumio[16068]: info: Dec 12 20:53:01 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:01 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:01 volumio volumio[16068]: info: ------------------------------ 1625ms Dec 12 20:53:01 volumio volumio[16068]: info: ------------------------------ 1738ms Dec 12 20:53:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87325. Dec 12 20:53:01 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:01 volumio volumio[16068]: info: Dec 12 20:53:01 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:01 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:01 volumio volumio[16068]: info: ------------------------------ 1930ms Dec 12 20:53:01 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:01 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:01 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:01 volumio go-librespot[21869]: Librespot-go daemon starting... Dec 12 20:53:01 volumio go-librespot[21869]: time="2025-12-12T20:53:01+01:00" level=info msg="generated new device id: 1f97de158fe4c59009c744f77b8eaca558353fac" Dec 12 20:53:01 volumio go-librespot[21869]: time="2025-12-12T20:53:01+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:01 volumio volumio[16068]: info: ------------------------------ 1949ms Dec 12 20:53:02 volumio go-librespot[21869]: time="2025-12-12T20:53:02+01:00" level=debug msg="obtained new client token: AADhOXjImonotzxmmnw4C2MKrxMLrckdYwttsh35bfjOrnblOA+FlVsAgtmblnNEnqvw+lu9ZdRmojWHG80xdRbMTx09yjbDHVKG2Tog1+MPB8pJYhmOdifPbG02E3tjUqSauYEm8H/vyM1Ej39oeUJYQQSSgrOUhti+jOuFZs0vjlE8BbDw4Ey3nDUX5Zx4/UCzXCguS20vYuZaB9D9Pc/pH+jV8PlPJwK/+oUrxPsqHXu4CXtDXstDpWeZm2ay" Dec 12 20:53:02 volumio volumio[16068]: info: ------------------------------ 2263ms Dec 12 20:53:02 volumio volumio[16068]: info: ------------------------------ 2329ms Dec 12 20:53:02 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:02 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:02 volumio volumio[16068]: info: Consume mode Dec 12 20:53:02 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:02 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:02 volumio go-librespot[21869]: time="2025-12-12T20:53:02+01: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]" Dec 12 20:53:02 volumio volumio[16068]: info: ------------------------------ 2131ms Dec 12 20:53:02 volumio volumio[16068]: info: ------------------------------ 1502ms Dec 12 20:53:02 volumio go-librespot[21869]: time="2025-12-12T20:53:02+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:03 volumio volumio[16068]: info: ------------------------------ 1289ms Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: ------------------------------ 272ms Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio go-librespot[21869]: time="2025-12-12T20:53:03+01:00" level=debug msg="completed challenge" Dec 12 20:53:03 volumio go-librespot[21869]: time="2025-12-12T20:53:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:03 volumio volumio[16068]: info: ------------------------------ 498ms Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: ------------------------------ 712ms Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:03 volumio volumio[16068]: info: Dec 12 20:53:03 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:03 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:04 volumio volumio[16068]: info: ------------------------------ 850ms Dec 12 20:53:04 volumio volumio[16068]: info: Dec 12 20:53:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:04 volumio volumio[16068]: info: ------------------------------ 1040ms Dec 12 20:53:04 volumio volumio[16068]: info: ------------------------------ 1157ms Dec 12 20:53:04 volumio volumio[16068]: info: Dec 12 20:53:04 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:04 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:04 volumio volumio[16068]: info: ------------------------------ 1370ms Dec 12 20:53:04 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:04 volumio volumio[16068]: info: ------------------------------ 1352ms Dec 12 20:53:04 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:05 volumio volumio[16068]: info: ------------------------------ 1534ms Dec 12 20:53:05 volumio volumio[16068]: info: Dec 12 20:53:05 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:05 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:05 volumio volumio[16068]: info: ------------------------------ 1555ms Dec 12 20:53:05 volumio volumio[16068]: info: ------------------------------ 1855ms Dec 12 20:53:05 volumio volumio[16068]: info: Dec 12 20:53:05 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:05 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:05 volumio volumio[16068]: info: ------------------------------ 2059ms Dec 12 20:53:06 volumio volumio[16068]: info: ------------------------------ 2220ms Dec 12 20:53:06 volumio volumio[16068]: info: ------------------------------ 2409ms Dec 12 20:53:06 volumio volumio[16068]: info: ------------------------------ 2265ms Dec 12 20:53:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87326. Dec 12 20:53:06 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:06 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:06 volumio go-librespot[21885]: Librespot-go daemon starting... Dec 12 20:53:06 volumio go-librespot[21885]: time="2025-12-12T20:53:06+01:00" level=info msg="generated new device id: bbee522bd48e849a5ca27625e388a70dcc5632d0" Dec 12 20:53:06 volumio go-librespot[21885]: time="2025-12-12T20:53:06+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:06 volumio volumio[16068]: info: ------------------------------ 2023ms Dec 12 20:53:06 volumio volumio[16068]: info: ------------------------------ 1831ms Dec 12 20:53:07 volumio go-librespot[21885]: time="2025-12-12T20:53:07+01:00" level=debug msg="obtained new client token: AABNNVEOaPWrXHiFn/4P7hcIqh9muC7HPAqEprokldNRO4EUvney5VZno5/uH7JEMNM4GJzqNvBoJ3s4tjmdyhGl5qEUOBDUOudfR+Qp7Jwe0SVI2tjIDCMQskN5thFLO1WQkUW2+UUg7yXBo0fCfOZS81OeHGqIwYz9RGPwDPWpxzK7amGmcA8o1WUHDGRb3k8S206S3HeU8DgfwDiRnYLK9QLJL+rrIivhuibquIOJg5JFKQHrNLDg+qbdCw==" Dec 12 20:53:07 volumio volumio[16068]: info: ------------------------------ 1291ms Dec 12 20:53:07 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:07 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:07 volumio volumio[16068]: info: Consume mode Dec 12 20:53:07 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:07 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:07 volumio go-librespot[21885]: time="2025-12-12T20:53:07+01: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]" Dec 12 20:53:07 volumio go-librespot[21885]: time="2025-12-12T20:53:07+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: ------------------------------ 241ms Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:07 volumio volumio[16068]: info: Dec 12 20:53:07 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:07 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:08 volumio go-librespot[21885]: time="2025-12-12T20:53:08+01:00" level=debug msg="completed challenge" Dec 12 20:53:08 volumio volumio[16068]: info: ------------------------------ 412ms Dec 12 20:53:08 volumio go-librespot[21885]: time="2025-12-12T20:53:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: ------------------------------ 645ms Dec 12 20:53:08 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: socket hang up Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: ------------------------------ 799ms Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: Dec 12 20:53:08 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:08 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:08 volumio volumio[16068]: info: ------------------------------ 1006ms Dec 12 20:53:08 volumio volumio[16068]: info: ------------------------------ 1016ms Dec 12 20:53:09 volumio volumio[16068]: info: Dec 12 20:53:09 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:09 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:09 volumio volumio[16068]: info: ------------------------------ 1187ms Dec 12 20:53:09 volumio volumio[16068]: info: ------------------------------ 1201ms Dec 12 20:53:09 volumio volumio[16068]: info: ------------------------------ 1445ms Dec 12 20:53:09 volumio volumio[16068]: info: Dec 12 20:53:09 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:09 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:09 volumio volumio[16068]: info: ------------------------------ 1447ms Dec 12 20:53:10 volumio volumio[16068]: info: ------------------------------ 1607ms Dec 12 20:53:10 volumio volumio[16068]: info: Dec 12 20:53:10 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:10 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:10 volumio volumio[16068]: info: ------------------------------ 1808ms Dec 12 20:53:10 volumio volumio[16068]: info: ------------------------------ 1838ms Dec 12 20:53:10 volumio volumio[16068]: info: ------------------------------ 2054ms Dec 12 20:53:10 volumio volumio[16068]: info: ------------------------------ 2068ms Dec 12 20:53:11 volumio volumio[16068]: info: ------------------------------ 1899ms Dec 12 20:53:11 volumio volumio[16068]: info: ------------------------------ 1442ms Dec 12 20:53:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87327. Dec 12 20:53:11 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:11 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:11 volumio go-librespot[21943]: Librespot-go daemon starting... Dec 12 20:53:11 volumio go-librespot[21943]: time="2025-12-12T20:53:11+01:00" level=info msg="generated new device id: e3283efbf15f683c9ca23e99ec66845560e163fd" Dec 12 20:53:11 volumio go-librespot[21943]: time="2025-12-12T20:53:11+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:11 volumio volumio[16068]: info: ------------------------------ 1244ms Dec 12 20:53:11 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:11 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:11 volumio go-librespot[21943]: time="2025-12-12T20:53:11+01:00" level=debug msg="new websocket client" Dec 12 20:53:11 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:11 volumio volumio[16068]: info: Consume mode Dec 12 20:53:11 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:11 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:11 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:53:11 volumio go-librespot[21943]: time="2025-12-12T20:53:11+01:00" level=debug msg="obtained new client token: AABhbLIxUxPote3Sr+8Pkj023INRjwbPM/rRJwKbPgBiOM2wTQecX5/073AcCU4IAXeAdMr2YjnPoUqCKtvIosFdmIhX4hID/DMNrjMY+sA0Q96uLusM1z38xE04u5x49GT86QE7/WJxxwqyoGLe1oiZWP5daS2ckunEIFsUDSFMPtZbF2Z4GJoaLDo0fsTZzU35diKEBX966O2q051yLsIETf3+UFHIARKCoUG1iaiyw3H+seLUHIWSRBNWZH9S" Dec 12 20:53:11 volumio go-librespot[21943]: time="2025-12-12T20:53:11+01: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]" Dec 12 20:53:11 volumio volumio[16068]: info: Dec 12 20:53:11 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:11 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:11 volumio volumio[16068]: info: Dec 12 20:53:11 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:11 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:11 volumio volumio[16068]: info: Dec 12 20:53:11 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:11 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: ------------------------------ 226ms Dec 12 20:53:12 volumio go-librespot[21943]: time="2025-12-12T20:53:12+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: ------------------------------ 501ms Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: ------------------------------ 672ms Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio go-librespot[21943]: time="2025-12-12T20:53:12+01:00" level=debug msg="completed challenge" Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio go-librespot[21943]: time="2025-12-12T20:53:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:12 volumio volumio[16068]: info: ------------------------------ 841ms Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Dec 12 20:53:12 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:12 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:12 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:53:13 volumio volumio[16068]: info: Dec 12 20:53:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:13 volumio volumio[16068]: info: ------------------------------ 1041ms Dec 12 20:53:13 volumio volumio[16068]: info: ------------------------------ 1084ms Dec 12 20:53:13 volumio volumio[16068]: info: Dec 12 20:53:13 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:13 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:13 volumio volumio[16068]: info: ------------------------------ 1374ms Dec 12 20:53:13 volumio volumio[16068]: info: ------------------------------ 1172ms Dec 12 20:53:13 volumio volumio[16068]: info: ------------------------------ 1344ms Dec 12 20:53:14 volumio volumio[16068]: info: Dec 12 20:53:14 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:14 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:14 volumio volumio[16068]: info: ------------------------------ 1547ms Dec 12 20:53:14 volumio volumio[16068]: info: ------------------------------ 1672ms Dec 12 20:53:14 volumio volumio[16068]: info: Dec 12 20:53:14 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:14 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:14 volumio volumio[16068]: info: ------------------------------ 1878ms Dec 12 20:53:14 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:53:14 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:14 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:53:14 volumio volumio[16068]: (node:16068) 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: 23247) Dec 12 20:53:15 volumio volumio[16068]: info: ------------------------------ 2141ms Dec 12 20:53:15 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:53:15 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:15 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:15 volumio volumio[16068]: info: Consume mode Dec 12 20:53:15 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:15 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:15 volumio volumio[16068]: info: ------------------------------ 2415ms Dec 12 20:53:15 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:15 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:15 volumio volumio[16068]: info: ------------------------------ 2449ms Dec 12 20:53:15 volumio volumio[16068]: info: ------------------------------ 2097ms Dec 12 20:53:15 volumio volumio[16068]: info: Dec 12 20:53:15 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:15 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:15 volumio volumio[16068]: info: Dec 12 20:53:15 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:15 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:15 volumio volumio[16068]: info: ------------------------------ 1798ms Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87328. Dec 12 20:53:16 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:16 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:16 volumio go-librespot[21969]: Librespot-go daemon starting... Dec 12 20:53:16 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:16 volumio go-librespot[21969]: time="2025-12-12T20:53:16+01:00" level=info msg="generated new device id: 3cffc809fec185f0103f8e6c57b7528a6fc5e5be" Dec 12 20:53:16 volumio go-librespot[21969]: time="2025-12-12T20:53:16+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: ------------------------------ 1614ms Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: ------------------------------ 750ms Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio go-librespot[21969]: time="2025-12-12T20:53:16+01:00" level=debug msg="obtained new client token: AADXkkfDz1fhjyZjMbCJb2g4LmUbqYFpU376/84sttH766cJoFuYHqeyYYtR+1C438jXhgOv8rGMZTfrAH1eMd1xWnW68SSqChgDX1uB3KZv1Zb6mTRwMpAypx2/AkXaxZjCnbEMKhwDb1Q4wePgP9o9ryPoya/49ZpPq9aHZf5881iK6KEvodEKM3FzU8vhhXLuMI+6L5RTVjgvG/+DVcMGMvNoL1TdhSNj08wTNI825QTYl4fuq02fndzj2aP3" Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: ------------------------------ 953ms Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio volumio[16068]: info: Dec 12 20:53:16 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:16 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:16 volumio go-librespot[21969]: time="2025-12-12T20:53:16+01: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]" Dec 12 20:53:16 volumio volumio[16068]: info: ------------------------------ 924ms Dec 12 20:53:16 volumio go-librespot[21969]: time="2025-12-12T20:53:16+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:17 volumio volumio[16068]: info: Dec 12 20:53:17 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:17 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:17 volumio volumio[16068]: info: ------------------------------ 1143ms Dec 12 20:53:17 volumio volumio[16068]: info: ------------------------------ 1175ms Dec 12 20:53:17 volumio go-librespot[21969]: time="2025-12-12T20:53:17+01:00" level=debug msg="completed challenge" Dec 12 20:53:17 volumio go-librespot[21969]: time="2025-12-12T20:53:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:17 volumio volumio[16068]: info: ------------------------------ 1355ms Dec 12 20:53:17 volumio volumio[16068]: info: Dec 12 20:53:17 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:17 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:17 volumio volumio[16068]: info: ------------------------------ 1524ms Dec 12 20:53:17 volumio volumio[16068]: info: ------------------------------ 1645ms Dec 12 20:53:18 volumio volumio[16068]: info: Dec 12 20:53:18 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:18 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:18 volumio volumio[16068]: info: ------------------------------ 1822ms Dec 12 20:53:18 volumio volumio[16068]: info: ------------------------------ 1868ms Dec 12 20:53:18 volumio volumio[16068]: info: Dec 12 20:53:18 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:18 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:18 volumio volumio[16068]: info: ------------------------------ 2103ms Dec 12 20:53:18 volumio volumio[16068]: info: ------------------------------ 2098ms Dec 12 20:53:18 volumio volumio[16068]: info: ------------------------------ 2274ms Dec 12 20:53:18 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:18 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:18 volumio volumio[16068]: info: Consume mode Dec 12 20:53:18 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:18 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:19 volumio volumio[16068]: info: ------------------------------ 2460ms Dec 12 20:53:19 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:19 volumio volumio[16068]: info: ------------------------------ 2173ms Dec 12 20:53:19 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:19 volumio volumio[16068]: info: ------------------------------ 1882ms Dec 12 20:53:19 volumio volumio[16068]: info: Dec 12 20:53:19 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:19 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:19 volumio volumio[16068]: info: Dec 12 20:53:19 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:19 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:19 volumio volumio[16068]: info: ------------------------------ 1736ms Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: ------------------------------ 1478ms Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: ------------------------------ 563ms Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: ------------------------------ 775ms Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio volumio[16068]: info: Dec 12 20:53:20 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:20 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87329. Dec 12 20:53:20 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:20 volumio volumio[16068]: info: ------------------------------ 742ms Dec 12 20:53:20 volumio go-librespot[21987]: Librespot-go daemon starting... Dec 12 20:53:20 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:20 volumio go-librespot[21987]: time="2025-12-12T20:53:20+01:00" level=info msg="generated new device id: d6c7c34dcc7d91bfaabfd3d98a44642f2ad30e59" Dec 12 20:53:20 volumio go-librespot[21987]: time="2025-12-12T20:53:20+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:21 volumio volumio[16068]: info: ------------------------------ 1000ms Dec 12 20:53:21 volumio volumio[16068]: info: Dec 12 20:53:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:21 volumio volumio[16068]: info: Dec 12 20:53:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:21 volumio go-librespot[21987]: time="2025-12-12T20:53:21+01:00" level=debug msg="obtained new client token: AAA3bei4O0Fds3+fBd2sjPnoKSsVcPZTKYZINLzpQkuxRlv4Heam0LQfbAFJW2rL8vDrwZ6GWU6SI4IMOadEXkeXmyiUVkvm49AvhSlF7fWEFYJukeLdwqfY7sEOAcw3RTSbt/ej/x4rGooCMP7MdcYnOulAptn5bqcoGqLBWMFiF+bWElFR4zpFZm8cfxJnH/U0PJA5/b1kU0eWE0Y0Tn4E79woZY5OIgiLoND2ZGLV1dhY/+oY6N37YKJPKQ==" Dec 12 20:53:21 volumio volumio[16068]: info: Dec 12 20:53:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:21 volumio volumio[16068]: info: ------------------------------ 1239ms Dec 12 20:53:21 volumio volumio[16068]: info: ------------------------------ 1395ms Dec 12 20:53:21 volumio go-librespot[21987]: time="2025-12-12T20:53:21+01: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]" Dec 12 20:53:21 volumio volumio[16068]: info: Dec 12 20:53:21 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:21 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:21 volumio volumio[16068]: info: ------------------------------ 1582ms Dec 12 20:53:21 volumio go-librespot[21987]: time="2025-12-12T20:53:21+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:21 volumio volumio[16068]: info: ------------------------------ 1684ms Dec 12 20:53:22 volumio volumio[16068]: info: ------------------------------ 1918ms Dec 12 20:53:22 volumio go-librespot[21987]: time="2025-12-12T20:53:22+01:00" level=debug msg="completed challenge" Dec 12 20:53:22 volumio volumio[16068]: info: Dec 12 20:53:22 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:22 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:22 volumio volumio[16068]: info: ------------------------------ 1936ms Dec 12 20:53:22 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:22 volumio go-librespot[21987]: time="2025-12-12T20:53:22+01:00" level=debug msg="new websocket client" Dec 12 20:53:22 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:53:22 volumio go-librespot[21987]: time="2025-12-12T20:53:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:22 volumio volumio[16068]: info: ------------------------------ 2071ms Dec 12 20:53:22 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:53:22 volumio volumio[16068]: info: Dec 12 20:53:22 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:22 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:22 volumio volumio[16068]: info: ------------------------------ 2282ms Dec 12 20:53:23 volumio volumio[16068]: info: ------------------------------ 1999ms Dec 12 20:53:23 volumio volumio[16068]: info: ------------------------------ 2268ms Dec 12 20:53:23 volumio volumio[16068]: info: ------------------------------ 2284ms Dec 12 20:53:23 volumio volumio[16068]: info: ------------------------------ 2052ms Dec 12 20:53:23 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:23 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:23 volumio volumio[16068]: info: Consume mode Dec 12 20:53:23 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:23 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:23 volumio volumio[16068]: info: ------------------------------ 1537ms Dec 12 20:53:24 volumio volumio[16068]: info: ------------------------------ 1302ms Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: ------------------------------ 295ms Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: ------------------------------ 551ms Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:24 volumio volumio[16068]: info: Dec 12 20:53:24 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:24 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: ------------------------------ 758ms Dec 12 20:53:25 volumio volumio[16068]: info: ------------------------------ 872ms Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: ------------------------------ 1068ms Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: Dec 12 20:53:25 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:25 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:25 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:53:25 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:25 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:53:25 volumio volumio[16068]: (node:16068) 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: 23248) Dec 12 20:53:25 volumio volumio[16068]: info: ------------------------------ 1003ms Dec 12 20:53:25 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:25 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:53:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87330. Dec 12 20:53:25 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:25 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:25 volumio go-librespot[22021]: Librespot-go daemon starting... Dec 12 20:53:25 volumio go-librespot[22021]: time="2025-12-12T20:53:25+01:00" level=info msg="generated new device id: 6684f058219589eb794a694dd360b56662b08c53" Dec 12 20:53:25 volumio go-librespot[22021]: time="2025-12-12T20:53:25+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:26 volumio volumio[16068]: info: Dec 12 20:53:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:26 volumio volumio[16068]: info: ------------------------------ 1368ms Dec 12 20:53:26 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:26 volumio go-librespot[22021]: time="2025-12-12T20:53:26+01:00" level=debug msg="obtained new client token: AAA6KA3RK9azOCG2b1gJVPgpQXD6sOTTqpbkKYG40BmhaGqSwh3XEfVQ8VuOSldap98XaNSfz0K9yiZLDhWddXJGfsTzev0coETiKKBFyDhBdfBHIMxUHQoJTCexhBgwlHBN9PLmGVGs2RmcaRIeTZ77/UK40MgnA5uhuw/qhwQyU6AlSzDQbsJVGLnJ+a1Hk6SBWgJzQ0L+MwMvRfSx7207wETF+8knu++H2jo9tnnghxjCnIsUqS4e86fZ+A==" Dec 12 20:53:26 volumio volumio[16068]: info: ------------------------------ 1420ms Dec 12 20:53:26 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:26 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:26 volumio go-librespot[22021]: time="2025-12-12T20:53:26+01: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]" Dec 12 20:53:26 volumio go-librespot[22021]: time="2025-12-12T20:53:26+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:26 volumio volumio[16068]: info: ------------------------------ 1658ms Dec 12 20:53:26 volumio volumio[16068]: info: Dec 12 20:53:26 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:26 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:26 volumio volumio[16068]: info: ------------------------------ 1702ms Dec 12 20:53:26 volumio volumio[16068]: info: ------------------------------ 1699ms Dec 12 20:53:27 volumio go-librespot[22021]: time="2025-12-12T20:53:27+01:00" level=debug msg="completed challenge" Dec 12 20:53:27 volumio go-librespot[22021]: time="2025-12-12T20:53:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:27 volumio volumio[16068]: info: Dec 12 20:53:27 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:27 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:27 volumio volumio[16068]: info: ------------------------------ 1934ms Dec 12 20:53:27 volumio volumio[16068]: info: ------------------------------ 2142ms Dec 12 20:53:27 volumio volumio[16068]: info: ------------------------------ 2388ms Dec 12 20:53:28 volumio volumio[16068]: info: ------------------------------ 2567ms Dec 12 20:53:28 volumio volumio[16068]: info: ------------------------------ 2168ms Dec 12 20:53:28 volumio volumio[16068]: info: ------------------------------ 1672ms Dec 12 20:53:28 volumio volumio[16068]: info: ------------------------------ 1488ms Dec 12 20:53:28 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:28 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:28 volumio volumio[16068]: info: Consume mode Dec 12 20:53:28 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:28 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:29 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:29 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: ------------------------------ 251ms Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: ------------------------------ 416ms Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:29 volumio volumio[16068]: info: ------------------------------ 584ms Dec 12 20:53:29 volumio volumio[16068]: info: ------------------------------ 703ms Dec 12 20:53:29 volumio volumio[16068]: info: Dec 12 20:53:29 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:29 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio volumio[16068]: info: ------------------------------ 904ms Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87331. Dec 12 20:53:30 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:30 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:30 volumio go-librespot[22033]: Librespot-go daemon starting... Dec 12 20:53:30 volumio go-librespot[22033]: time="2025-12-12T20:53:30+01:00" level=info msg="generated new device id: 5a14ad655c925d4468aeba85d1529149cbf3bfab" Dec 12 20:53:30 volumio go-librespot[22033]: time="2025-12-12T20:53:30+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:30 volumio volumio[16068]: info: ------------------------------ 1048ms Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces state update: player Dec 12 20:53:30 volumio volumio[16068]: info: ControllerMpd::getState Dec 12 20:53:30 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand status Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces state update: player Dec 12 20:53:30 volumio volumio[16068]: info: ControllerMpd::getState Dec 12 20:53:30 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand status Dec 12 20:53:30 volumio go-librespot[22033]: time="2025-12-12T20:53:30+01:00" level=debug msg="obtained new client token: AADu3c5JCHAR3s9DPpXQP0yvkN/Pi7LjLAWBvDRtZDAKxhSqCzZoO8hB7CUtRke7YVEk4Q6vqdwhBiXO0o/MyeGd6IfqVNISziRLQtzZ31aSvbL+YvqwW9Ra3vjRydF4GLxbS4E/+aO3xgpR1TqLOJWay9859TvZ09hEI4ZHXssTserC1YuNN52MGoqJtBfpbDMYYY9WF0UMOaop8J3kmIEWAwZWIVb/CWSOQATuQTmO55mJIZkLY8JxWCiES6aB" Dec 12 20:53:30 volumio volumio[16068]: info: Dec 12 20:53:30 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:30 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:30 volumio volumio[16068]: info: ------------------------------ 1281ms Dec 12 20:53:30 volumio go-librespot[22033]: time="2025-12-12T20:53:30+01: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]" Dec 12 20:53:30 volumio go-librespot[22033]: time="2025-12-12T20:53:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Dec 12 20:53:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:30 volumio volumio[16068]: info: ------------------------------ 1345ms Dec 12 20:53:31 volumio volumio[16068]: info: ------------------------------ 1536ms Dec 12 20:53:31 volumio volumio[16068]: info: Dec 12 20:53:31 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:31 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:31 volumio volumio[16068]: info: ------------------------------ 1592ms Dec 12 20:53:31 volumio volumio[16068]: info: ------------------------------ 1730ms Dec 12 20:53:31 volumio volumio[16068]: info: Dec 12 20:53:31 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:31 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:31 volumio volumio[16068]: info: ------------------------------ 1952ms Dec 12 20:53:32 volumio volumio[16068]: info: ------------------------------ 1978ms Dec 12 20:53:32 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:32 volumio volumio[16068]: info: ------------------------------ 2167ms Dec 12 20:53:32 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:32 volumio volumio[16068]: info: Dec 12 20:53:32 volumio volumio[16068]: ---------------------------- MPD announces state update: player Dec 12 20:53:32 volumio volumio[16068]: info: ------------------------------ 2364ms Dec 12 20:53:32 volumio volumio[16068]: info: ControllerMpd::getState Dec 12 20:53:32 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand status Dec 12 20:53:32 volumio volumio[16068]: info: sendMpdCommand status took 2006 milliseconds Dec 12 20:53:32 volumio volumio[16068]: info: sendMpdCommand status took 2002 milliseconds Dec 12 20:53:32 volumio volumio[16068]: verbose: ControllerMpd::parseState Dec 12 20:53:32 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 12 20:53:32 volumio volumio[16068]: verbose: ControllerMpd::parseState Dec 12 20:53:32 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 12 20:53:32 volumio volumio[16068]: info: ------------------------------ 2011ms Dec 12 20:53:32 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:32 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:32 volumio volumio[16068]: info: Consume mode Dec 12 20:53:32 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:32 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 1635ms Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 1273ms Dec 12 20:53:33 volumio volumio[16068]: info: sendMpdCommand status took 662 milliseconds Dec 12 20:53:33 volumio volumio[16068]: info: sendMpdCommand playlistinfo took 659 milliseconds Dec 12 20:53:33 volumio volumio[16068]: info: sendMpdCommand playlistinfo took 658 milliseconds Dec 12 20:53:33 volumio volumio[16068]: verbose: ControllerMpd::parseState Dec 12 20:53:33 volumio volumio[16068]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 12 20:53:33 volumio volumio[16068]: verbose: ControllerMpd::parseTrackInfo Dec 12 20:53:33 volumio volumio[16068]: verbose: ControllerMpd::parseTrackInfo Dec 12 20:53:33 volumio volumio[16068]: info: ControllerMpd::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::servicePushState Dec 12 20:53:33 volumio volumio[16068]: verbose: In UPNP mode Dec 12 20:53:33 volumio volumio[16068]: verbose: STATE SERVICE {"status":"play","position":21,"seek":22,"duration":309,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"881 Kbps","isStreaming":false,"title":"Sausalito Summernight","artist":"Diesel","album":"On The Rocks","uri":"http://192.168.0.105:57645/proxy/tidal/563361AEDB894BC8F493000882E99E5A.flac","trackType":"tidal"} Dec 12 20:53:33 volumio volumio[16068]: verbose: CURRENT POSITION 0 Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState stateService play Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState currentStatus play Dec 12 20:53:33 volumio volumio[16068]: info: Received an update from plugin. extracting info from payload Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: ControllerMpd::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::servicePushState Dec 12 20:53:33 volumio volumio[16068]: verbose: In UPNP mode Dec 12 20:53:33 volumio volumio[16068]: verbose: STATE SERVICE {"status":"play","position":21,"seek":22,"duration":309,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"881 Kbps","isStreaming":false,"title":"Sausalito Summernight","artist":"Diesel","album":"On The Rocks","uri":"http://192.168.0.105:57645/proxy/tidal/563361AEDB894BC8F493000882E99E5A.flac","trackType":"tidal"} Dec 12 20:53:33 volumio volumio[16068]: verbose: CURRENT POSITION 0 Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState stateService play Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState currentStatus play Dec 12 20:53:33 volumio volumio[16068]: info: Received an update from plugin. extracting info from payload Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 2711ms Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 2708ms Dec 12 20:53:33 volumio volumio[16068]: info: sendMpdCommand playlistinfo took 44 milliseconds Dec 12 20:53:33 volumio volumio[16068]: verbose: ControllerMpd::parseTrackInfo Dec 12 20:53:33 volumio volumio[16068]: info: ControllerMpd::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::servicePushState Dec 12 20:53:33 volumio volumio[16068]: verbose: In UPNP mode Dec 12 20:53:33 volumio volumio[16068]: verbose: STATE SERVICE {"status":"play","position":21,"seek":2013,"duration":309,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"925 Kbps","isStreaming":false,"title":"Sausalito Summernight","artist":"Diesel","album":"On The Rocks","uri":"http://192.168.0.105:57645/proxy/tidal/563361AEDB894BC8F493000882E99E5A.flac","trackType":"tidal"} Dec 12 20:53:33 volumio volumio[16068]: verbose: CURRENT POSITION 0 Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState stateService play Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::syncState currentStatus play Dec 12 20:53:33 volumio volumio[16068]: info: Received an update from plugin. extracting info from payload Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::pushState Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioPushState Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 727ms Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreCommandRouter::volumioGetQueue Dec 12 20:53:33 volumio volumio[16068]: info: CoreStateMachine::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: CorePlayQueue::getQueue Dec 12 20:53:33 volumio volumio[16068]: info: [LastFM] Current track has sufficient metadata: title (Sausalito Summernight) and artist (Diesel) passed on explicitly Dec 12 20:53:33 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:33 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:33 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:33 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 296ms Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: ------------------------------ 489ms Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:33 volumio volumio[16068]: info: Dec 12 20:53:33 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:33 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87332. Dec 12 20:53:34 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:34 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:34 volumio go-librespot[22062]: Librespot-go daemon starting... Dec 12 20:53:34 volumio go-librespot[22062]: time="2025-12-12T20:53:34+01:00" level=info msg="generated new device id: afb7c0ac8cf1ffa034418acbc1145b48ad2fde8f" Dec 12 20:53:34 volumio go-librespot[22062]: time="2025-12-12T20:53:34+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: ------------------------------ 718ms Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: ------------------------------ 671ms Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio go-librespot[22062]: time="2025-12-12T20:53:34+01:00" level=debug msg="obtained new client token: AAC0VnfnEVYHd0C4nV4aqkmcNYDoOXqQgpJQylawXQfs4oQM5RUmyoxV20aQvFTuSNhcruYAykcB44kI3Hiva4SR5dNZ/A54y5TNV/wDxr94g4i6Fgpa+/79wNclFAr12gzFCKbw/RRxirWVGUodf1cM0XL0+SyrSD5qwrZMQs2/6G4mMegmx0W9xB4YClnU3xLpMwub1vAHDpgz874IaYEa8TR1ywWAJ34nS87mNzTjCaiFYvfBh6wO0PV/8zPS" Dec 12 20:53:34 volumio go-librespot[22062]: time="2025-12-12T20:53:34+01: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]" Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: ------------------------------ 953ms Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio volumio[16068]: info: Dec 12 20:53:34 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:34 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:34 volumio go-librespot[22062]: time="2025-12-12T20:53:34+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:34 volumio volumio[16068]: info: ------------------------------ 1001ms Dec 12 20:53:35 volumio volumio[16068]: info: ------------------------------ 1190ms Dec 12 20:53:35 volumio volumio[16068]: info: Dec 12 20:53:35 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:35 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:35 volumio volumio[16068]: info: ------------------------------ 1177ms Dec 12 20:53:35 volumio go-librespot[22062]: time="2025-12-12T20:53:35+01:00" level=debug msg="completed challenge" Dec 12 20:53:35 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:35 volumio go-librespot[22062]: time="2025-12-12T20:53:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:35 volumio volumio[16068]: info: ------------------------------ 1338ms Dec 12 20:53:35 volumio volumio[16068]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:35 volumio volumio[16068]: info: Dec 12 20:53:35 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:35 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:35 volumio volumio[16068]: info: ------------------------------ 1668ms Dec 12 20:53:36 volumio volumio[16068]: info: ------------------------------ 1714ms Dec 12 20:53:36 volumio volumio[16068]: info: Dec 12 20:53:36 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:36 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:36 volumio volumio[16068]: info: ------------------------------ 1903ms Dec 12 20:53:36 volumio volumio[16068]: info: ------------------------------ 1886ms Dec 12 20:53:36 volumio volumio[16068]: info: ------------------------------ 2077ms Dec 12 20:53:37 volumio volumio[16068]: info: ------------------------------ 2333ms Dec 12 20:53:37 volumio volumio[16068]: info: ------------------------------ 1929ms Dec 12 20:53:37 volumio volumio[16068]: info: ------------------------------ 1600ms Dec 12 20:53:37 volumio volumio[16068]: info: ------------------------------ 1383ms Dec 12 20:53:37 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:37 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:37 volumio volumio[16068]: info: Consume mode Dec 12 20:53:37 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:37 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: ------------------------------ 272ms Dec 12 20:53:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87333. Dec 12 20:53:38 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:38 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:38 volumio go-librespot[22079]: Librespot-go daemon starting... Dec 12 20:53:38 volumio go-librespot[22079]: time="2025-12-12T20:53:38+01:00" level=info msg="generated new device id: 4fca658fa4fc79c041091b0f941fd51a8973f3dd" Dec 12 20:53:38 volumio go-librespot[22079]: time="2025-12-12T20:53:38+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:38 volumio volumio[16068]: info: ------------------------------ 627ms Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Dec 12 20:53:38 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:38 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:38 volumio volumio[16068]: info: Initializing connection to go-librespot Websocket Dec 12 20:53:38 volumio go-librespot[22079]: time="2025-12-12T20:53:38+01:00" level=debug msg="new websocket client" Dec 12 20:53:38 volumio volumio[16068]: info: Connection to go-librespot Websocket established Dec 12 20:53:38 volumio go-librespot[22079]: time="2025-12-12T20:53:38+01:00" level=debug msg="obtained new client token: AAAJvut9pZsyRBKkHb0xfo5mtazCO4bM9tPhWL1j4NghGmtryF9ie1TwF5RUHQqKrNuBufLXrySoyPbozyt6FVkfN37Ud1NU3x3NaSmPh7M5EY9A6mwHFAgmgE+47TE9polOwU2WkMsA9AmMEcL04W6Jfyuu0lDGI2JHyiZJcn0RuIkgx8NGtwKenHo21ZVSH5GI3LoztUlC2kIN+x9GNEwZ2kL8GQYOsltQyPzp7NOds3du44g7N3oMHc98ckcu" Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio volumio[16068]: info: ------------------------------ 873ms Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio go-librespot[22079]: time="2025-12-12T20:53:39+01: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]" Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio volumio[16068]: info: ------------------------------ 1018ms Dec 12 20:53:39 volumio go-librespot[22079]: time="2025-12-12T20:53:39+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:39 volumio volumio[16068]: info: Dec 12 20:53:39 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:39 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:39 volumio volumio[16068]: info: ------------------------------ 1220ms Dec 12 20:53:39 volumio volumio[16068]: info: ------------------------------ 1219ms Dec 12 20:53:39 volumio go-librespot[22079]: time="2025-12-12T20:53:39+01:00" level=debug msg="completed challenge" Dec 12 20:53:39 volumio go-librespot[22079]: time="2025-12-12T20:53:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:40 volumio volumio[16068]: info: Dec 12 20:53:40 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:40 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:40 volumio volumio[16068]: info: ------------------------------ 1516ms Dec 12 20:53:40 volumio volumio[16068]: info: Connection to go-librespot Websocket closed Dec 12 20:53:40 volumio volumio[16068]: info: ------------------------------ 1397ms Dec 12 20:53:40 volumio volumio[16068]: info: Dec 12 20:53:40 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:40 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:40 volumio volumio[16068]: info: ------------------------------ 1604ms Dec 12 20:53:40 volumio volumio[16068]: info: ------------------------------ 1594ms Dec 12 20:53:40 volumio volumio[16068]: info: ------------------------------ 1772ms Dec 12 20:53:41 volumio volumio[16068]: info: Dec 12 20:53:41 volumio volumio[16068]: ---------------------------- MPD announces system playlist update Dec 12 20:53:41 volumio volumio[16068]: info: Ignoring MPD Status Update Dec 12 20:53:41 volumio volumio[16068]: info: ------------------------------ 2012ms Dec 12 20:53:41 volumio volumio[16068]: info: ------------------------------ 2326ms Dec 12 20:53:41 volumio volumio[16068]: info: ------------------------------ 2602ms Dec 12 20:53:41 volumio volumio[16068]: info: ------------------------------ 2445ms Dec 12 20:53:41 volumio volumio[16068]: info: Getting Spotify volume Dec 12 20:53:42 volumio volumio[16068]: info: Starting UPNP Playback Dec 12 20:53:42 volumio volumio[16068]: info: Preparing playback through UPNP Dec 12 20:53:42 volumio volumio[16068]: info: Consume mode Dec 12 20:53:42 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:42 volumio volumio[16068]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 12 20:53:42 volumio volumio[16068]: (node:16068) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 20:53:42 volumio volumio[16068]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 12 20:53:42 volumio volumio[16068]: (node:16068) 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: 23249) Dec 12 20:53:42 volumio volumio[16068]: info: ------------------------------ 2159ms Dec 12 20:53:42 volumio volumio[16068]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 12 20:53:42 volumio volumio[16068]: info: ------------------------------ 1946ms Dec 12 20:53:42 volumio volumio[16068]: info: CoreCommandRouter::volumioGetState Dec 12 20:53:42 volumio volumio[16068]: info: ------------------------------ 1581ms Dec 12 20:53:42 volumio volumio[16068]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Dec 12 20:53:42 volumio volumio[16068]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 20:53:42 volumio volumio[16068]: TypeError: Cannot read property '@' of undefined Dec 12 20:53:42 volumio volumio[16068]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Dec 12 20:53:42 volumio volumio[16068]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Dec 12 20:53:42 volumio volumio[16068]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Dec 12 20:53:42 volumio volumio[16068]: at Parser.emit (events.js:315:20) Dec 12 20:53:42 volumio volumio[16068]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Dec 12 20:53:42 volumio volumio[16068]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Dec 12 20:53:42 volumio volumio[16068]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Dec 12 20:53:42 volumio volumio[16068]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Dec 12 20:53:42 volumio volumio[16068]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Dec 12 20:53:42 volumio volumio[16068]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Dec 12 20:53:42 volumio volumio[16068]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Dec 12 20:53:42 volumio volumio[16068]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Dec 12 20:53:42 volumio volumio[16068]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Dec 12 20:53:42 volumio volumio[16068]: at IncomingMessage.emit (events.js:327:22) Dec 12 20:53:42 volumio volumio[16068]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 12 20:53:42 volumio volumio[16068]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 12 20:53:42 volumio volumio[16068]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 20:53:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 20:53:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87334. Dec 12 20:53:43 volumio systemd[1]: Stopped go-librespot Daemon. Dec 12 20:53:43 volumio systemd[1]: Started go-librespot Daemon. Dec 12 20:53:43 volumio go-librespot[22113]: Librespot-go daemon starting... Dec 12 20:53:43 volumio go-librespot[22113]: time="2025-12-12T20:53:43+01:00" level=info msg="generated new device id: 9b8d8ffc8371fe3c299ff0ba64d05360b3bd7a01" Dec 12 20:53:43 volumio go-librespot[22113]: time="2025-12-12T20:53:43+01:00" level=debug msg="stored credentials found for 1fvz1" Dec 12 20:53:43 volumio go-librespot[22113]: time="2025-12-12T20:53:43+01:00" level=debug msg="obtained new client token: AABeg3RZXnuw1vWb2WU+9cZd1F0FjOdgZHTqXuIX5AEgrUZ5ch8Inyecr7z+cLSbBdqaCOSZu7U2aDn/QuQcV57NXBUpNR1CY8OTBOnLEnX4uQEKhvzGHgAvvFURQG4da+zoo7QkepZCbr4fE0koaIruHQLhnJNrEinQN8ufaYveXKodZrGlOH1gV+/Ud4gkcvayDSoOGL+cgfztXTbRy7mTib2oSHpDkjvoyJ/FfL9IaDE+NjhhzZZnUxcf547z" Dec 12 20:53:43 volumio go-librespot[22113]: time="2025-12-12T20:53:43+01: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]" Dec 12 20:53:43 volumio go-librespot[22113]: time="2025-12-12T20:53:43+01:00" level=debug msg="completed keyexchange" Dec 12 20:53:44 volumio go-librespot[22113]: time="2025-12-12T20:53:44+01:00" level=debug msg="completed challenge" Dec 12 20:53:44 volumio go-librespot[22113]: time="2025-12-12T20:53:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Dec 12 20:53:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 20:53:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 20:53:44 volumio sudo[22129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-12 20:52 Dec 12 20:53:44 volumio sudo[22129]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"