-- Logs begin at Wed 2025-09-03 07:11:11 CEST, end at Wed 2025-09-03 09:20:10 CEST. -- Sep 03 09:19:00 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: (node:887) 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: 4344) Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:01 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:02 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:02 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:02 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:02 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13417. Sep 03 09:19:02 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:02 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: Librespot-go daemon starting... Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=info msg="generated new device id: 5feab74b732716a47c1b971ddb65e2ee9e765201" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="zeroconf server listening on port 37001" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="obtained new client token: AACaC+XrSmN3cip1Zb6cBcwdnIvF3E4ayezBRVHqRex3WNJN44GBpFmYx+CGM+Gm9pqD1abFaevF0NfkcvSq2QZfr0NeMEiwfzigDj0Z1J7t/ZuP9VHALYzZuFIl64bPMSbrkFOOVTlMAs3RAAhAUJqE4/7IYfmI2qhddm8sGt5pFsVIGKpIhmbzfx0DNvsAT+w68p28IzdJIw0vUt8h7snMgXfxtLxEsLYZG96KZrDopp/MmUOJmX1afOEY9g==" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:02 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:02+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:03 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:03+02:00" level=debug msg="completed challenge" Sep 03 09:19:03 volumio-rdc-dressing go-librespot[18360]: time="2025-09-03T09:19:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:03 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:03 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:05 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:05 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:06 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:06 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13418. Sep 03 09:19:06 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:06 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: Librespot-go daemon starting... Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=info msg="generated new device id: c3fc01838d106b728ee46b41dcf75a53360aba20" Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:06 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:06+02:00" level=debug msg="zeroconf server listening on port 33099" Sep 03 09:19:07 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:07+02:00" level=debug msg="obtained new client token: AAB7/HSuG67vkzqjJeW+lfy3F3GItOwyfyVOcr4lNSDf/5UzR5ukOTzRD2fK7plfzvAHH7Jvl30w7Wgazpo8MbxQy1hyVHm+YNO5fGNqXJopR5fBIrhpyv1qzSsEvEwGvt864LBT7TN9SckttFB/wFRth4AiIG+MPYzY4oLlb0FMBE838lBZc58yKfMiN7ZfuCD4mDXihlhFKbaX6WsLMzaBTgpxIhigVn8+Y9suiUcGDYo2Lq8KS+Up9Kw=" Sep 03 09:19:07 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:07+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:07 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:07+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:07 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:07+02:00" level=debug msg="completed challenge" Sep 03 09:19:07 volumio-rdc-dressing go-librespot[18368]: time="2025-09-03T09:19:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:07 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:07 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:08 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:08 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:08 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:10 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:10 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13419. Sep 03 09:19:10 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:10 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:10 volumio-rdc-dressing go-librespot[18377]: Librespot-go daemon starting... Sep 03 09:19:10 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:10+02:00" level=info msg="generated new device id: 74583ee1351b6ceca66d73bd0ab5121acf80ee4b" Sep 03 09:19:10 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:10+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="zeroconf server listening on port 40665" Sep 03 09:19:11 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="new websocket client" Sep 03 09:19:11 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="obtained new client token: AABaR3UAaePZUmpWdlfjO6F6xYXegOUbgnkAgbewR+sHMrTFPQCF+rXtnJYlFrJkyMAuByG7zvxRcEHLfyp3HVmR6FoMAUrMX9rj9rJXme26dkBKa73RxQbEYJmwLSOQUe3tvsuuFgCRIBg7sjDVwWBBHDWu/KmO4K90lUgi9L7+bl0LTq/JwqRerRgRKtXhbcj7gMO40xfMC9DhGvQRl4uNTXzk03fQZGCRZhgIoitqep5sgkfwu66ATBaDcw==" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=debug msg="completed challenge" Sep 03 09:19:11 volumio-rdc-dressing go-librespot[18377]: time="2025-09-03T09:19:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:11 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:19:11 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:11 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: (node:887) 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: 4345) Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:14 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:15 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:15 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13420. Sep 03 09:19:15 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:15 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: Librespot-go daemon starting... Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=info msg="generated new device id: 04636846ba55499b251102959f96359bfad27ae5" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="zeroconf server listening on port 40641" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="obtained new client token: AADommvzcPHVyzN6Vw6oZLrivOcBl7OwegPo8u674NdcqXmDzyqaUPN2ZuCyv/mmVmEn3obX6xTYGRpoLuySBehGtrIcmL58MqWKfCe0tVcTRVs1uG7a6JlgDlKzG014/AD85DhwHOV6JPa4kGV26LB9tfsUShCJ2DQ9t3PZ5iA7txxatN7vEYoJ4Z0t5azrvfq95ubxOryYyLaoOW0TgK4BR0S4Yga1y6mcjci/bz/WtNIfdTda0t2Xgg/Y+g==" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:15 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:15+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:16 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:16+02:00" level=debug msg="completed challenge" Sep 03 09:19:16 volumio-rdc-dressing go-librespot[18385]: time="2025-09-03T09:19:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:16 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:16 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:17 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:17 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:17 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:19 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:19 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13421. Sep 03 09:19:19 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:19 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: Librespot-go daemon starting... Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=info msg="generated new device id: e23c4e54a5e90653d2c3d89b35acc1e8abcc99bd" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="zeroconf server listening on port 41909" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="obtained new client token: AAAGlQq+XmG06K7tmApenQFynQVcFVnZ1Tbb8f/u86n0mBaHj8xfWahpTtbdH9y5S1m6QUaFnr2pZRKezb+1eLEjyCF9SQG1XmqbG1CR4PgjBWk14Wn/OJYNZT0E0G7gizUufVDDlnbHYW+46SEzBlSFw04IOCFJ46e/H7nbtA8uHdOZA4rMD4sBx2RZPcmE76cZtUalloMwSMdh2q6Vw4KdkV8fC9gJTZfc7Qzx0Hzz3fmaQ00nl/WmRI5Omw==" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:19 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:19+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:20 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:20+02:00" level=debug msg="completed challenge" Sep 03 09:19:20 volumio-rdc-dressing go-librespot[18394]: time="2025-09-03T09:19:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:20 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:20 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:21 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:21 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:23 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:23 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13422. Sep 03 09:19:23 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:23 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: Librespot-go daemon starting... Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=info msg="generated new device id: c2f6fc454b230462211e6cf94fdc82fa047fa07f" Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:23 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:23+02:00" level=debug msg="zeroconf server listening on port 43763" Sep 03 09:19:24 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=debug msg="new websocket client" Sep 03 09:19:24 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=debug msg="obtained new client token: AAC95M87BrL4Fm3+D9/d4BvTXBrxI8yOITnOwI5E4Q8mpd+b7EYv3f97znSfbX6dnv+uXmAmMPlvBTdyzp9TGrOVcCjs9jNDgnPxfGHHTaav7TIocUso1l/wR/baNHeTZ68UKhUaGSxA+NyFJlzK3i41xooRAuCtmu+b7o9dRMUjcRPIRNLKJCLy8NrKYbyoWzMePdZpQvYJ5KMh45Td6gyCBtgOVbsEZoPxkapmNrIGZZ36ATLJXVfQkjg=" Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=debug msg="completed challenge" Sep 03 09:19:24 volumio-rdc-dressing go-librespot[18402]: time="2025-09-03T09:19:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:24 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:19:24 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:24 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:25 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: (node:887) 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: 4346) Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:27 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:27 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:27 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13423. Sep 03 09:19:27 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:27 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:27 volumio-rdc-dressing go-librespot[18410]: Librespot-go daemon starting... Sep 03 09:19:27 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:27+02:00" level=info msg="generated new device id: 146788bc72c3806bfe87bf015bca532440ae19cf" Sep 03 09:19:27 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:27+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="zeroconf server listening on port 35787" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="obtained new client token: AAC5ANqohAhYB39azWmEwQ5i/Xn8L9a81mE59WHrhPG9RI190z9diMQvlqM3KDLP6C3pXVEsWHaFUdlE02A9OjKmNkIsQ5Co1P6ZjQdHtHX4v9cE+3BYkbIzUy1WQSk2e7EvYXI/QNo/y3q5oxgaEnlDA6zeScmvY8lpiQjXsHIY3T6IHZdC06TXf8O2UzCMQFpPmnW2NkcdxdKvxV3gkUGzYKG3tXLt0L3A3eiqSqTVLN/fzcA9AN8nL+8jQA==" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=debug msg="completed challenge" Sep 03 09:19:28 volumio-rdc-dressing go-librespot[18410]: time="2025-09-03T09:19:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:28 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:28 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: Discovery: Getting this device information Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to 10.0.0.54:3000 from 10.0.0.52 UA: Dart/3.5 (dart:io) Total Clients: 9 Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 03 09:19:29 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 03 09:19:30 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:30 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:32 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:32 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13424. Sep 03 09:19:32 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:32 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: Librespot-go daemon starting... Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=info msg="generated new device id: 6b9c63da11e0372d620fb409fdd0c06b4a39d254" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="zeroconf server listening on port 38273" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="obtained new client token: AACZeFObNCfWqMVMWsy/1tiQNlcNd751mG9QgP8R8ORRkvOelgPzLk8AlwtIDF/s8uFrXUP6r050YNAse4pygBV8WQjotFCVNk7t9lOUC1TbYfaHv3fbLNUUMkO6RCv1sX9M630NTVfT9AM40k+C8UfZW/RILm7Yru49VxaM3WZAhneLct3icncG2KEbfZjXtDSeYxGDzdlkqfvd68F8N3yHWCBYnJ4nN5qqx7iyvwI5rdKlCLfuW+8onkF/ag==" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:32 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:32+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:33 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:33+02:00" level=debug msg="completed challenge" Sep 03 09:19:33 volumio-rdc-dressing go-librespot[18419]: time="2025-09-03T09:19:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:33 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:33 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to 10.0.0.54:3000 from 10.0.0.52 UA: Dart/3.5 (dart:io) Total Clients: 10 Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:33 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:35 volumio-rdc-dressing sudo[18428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 03 09:19:35 volumio-rdc-dressing sudo[18428]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:19:35 volumio-rdc-dressing sudo[18428]: pam_unix(sudo:session): session closed for user root Sep 03 09:19:35 volumio-rdc-dressing sudo[18431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 03 09:19:35 volumio-rdc-dressing sudo[18431]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:19:35 volumio-rdc-dressing sudo[18431]: pam_unix(sudo:session): session closed for user root Sep 03 09:19:35 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to 10.0.0.54 from 10.0.0.52 UA: Mozilla/5.0 (Linux; Android 11; M2102J20SG Build/RKQ1.200826.002; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.143 Mobile Safari/537.36 Total Clients: 11 Sep 03 09:19:35 volumio-rdc-dressing sudo[18434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 03 09:19:35 volumio-rdc-dressing sudo[18434]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:19:35 volumio-rdc-dressing sudo[18434]: pam_unix(sudo:session): session closed for user root Sep 03 09:19:35 volumio-rdc-dressing sudo[18437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 03 09:19:35 volumio-rdc-dressing sudo[18437]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:19:35 volumio-rdc-dressing sudo[18437]: pam_unix(sudo:session): session closed for user root Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to 10.0.0.54 from 10.0.0.52 UA: Mozilla/5.0 (Linux; Android 11; M2102J20SG Build/RKQ1.200826.002; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.143 Mobile Safari/537.36 Total Clients: 12 Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: Listing playlists Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 03 09:19:36 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:36 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13425. Sep 03 09:19:36 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:36 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:36 volumio-rdc-dressing go-librespot[18439]: Librespot-go daemon starting... Sep 03 09:19:36 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:36+02:00" level=info msg="generated new device id: 4577d46bac7cf268307ea0e6dd9bd49dd4397211" Sep 03 09:19:36 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:36+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:36 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:36+02:00" level=debug msg="new websocket client" Sep 03 09:19:36 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="zeroconf server listening on port 40503" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="obtained new client token: AABCW2VLAroCMxxB+lRGAZQaUfh9uTb/6w6yEE8gwtZCTAAnaNd2v4N3eJulI2eaPTk4XFHIwV4+b7Os4R6NYuu7sF2YPUBOeOUiqGuM7pRWYRuL9puAqVBe570reugWPOQldNtGooMAHjfIFX5jWhM4JZnRKhTZjhs3ilrVr5PpC/Hxd0TRrlLbzVQIA+UlDF/IE8qH9GTELJEdRdAKEUx6SsbWYAyYjRs8s64wvReM8+4BtlzgXSzeqoU=" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=debug msg="completed challenge" Sep 03 09:19:37 volumio-rdc-dressing go-librespot[18439]: time="2025-09-03T09:19:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:37 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:37 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:37 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: (node:887) 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: 4347) Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetQueue Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: CoreStateMachine::getQueue Sep 03 09:19:39 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getQueue Sep 03 09:19:40 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:40 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:41 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:41 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13426. Sep 03 09:19:41 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:41 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: Librespot-go daemon starting... Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=info msg="generated new device id: 38f4a4dba7daae8292507db24ce077894dd78a65" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="zeroconf server listening on port 43383" Sep 03 09:19:41 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="obtained new client token: AADiJdXzidpOXDWAB/SCXQu/JFMeYFauoEJ7ILX+CnD3CaQq8KevPTPDTQ0PP+zb64WIByI2YXs/GoIv6NmP24tso6pvc9a8GFrw1vwd/lJAxaCm3yFJTYte/FrCLPw0BNvg8ePgMS1V1etbsbLO8p8fz/NOHB2eB5eLGHh+V475k+/pgv2tkdK/Wy/0CSAgxxexhrdze/I4H3AlJJBIP7nHyTebdobEPHQefzNK4zMR1HTnAScWI0J6XZFVAg==" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:41 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:41+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:42 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:42+02:00" level=debug msg="completed challenge" Sep 03 09:19:42 volumio-rdc-dressing go-librespot[18448]: time="2025-09-03T09:19:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:42 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:42 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:42 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 03 09:19:42 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 03 09:19:42 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:19:42 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:43 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:45 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:45 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13427. Sep 03 09:19:45 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:45 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: Librespot-go daemon starting... Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=info msg="generated new device id: 2319e8d368e8a29b1ca3b3971e46af2283d80bcd" Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:45 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:45+02:00" level=debug msg="zeroconf server listening on port 43891" Sep 03 09:19:46 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:46+02:00" level=debug msg="obtained new client token: AAA+uO1PMiwG6+qgCyqVQpgo+mCET18WSx3UQ3SPacaAXIQSheOV0Am7uckLGIVNrOQq3L66gXP6CAiwNJrpZ+nqFltXHyuASCMg7Q4rg2229uhNqg1InRYeiWDWg8Bv7Yhm+WbHY4qRsnOpnIcMCnn/IFsibxW8hiBmQCTeMcdwmR+acc4Bv5VCvtlxzj9CVEX3tnueRo5bR45zc1cwZuMvXDK8Ovlt0w7pvgFW8OjRUR1uYN/N1sQ9qpc=" Sep 03 09:19:46 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:46+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:46 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:46+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:46 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:46+02:00" level=debug msg="completed challenge" Sep 03 09:19:46 volumio-rdc-dressing go-librespot[18461]: time="2025-09-03T09:19:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:46 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:46 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:46 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:46 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:49 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:49 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:49 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13428. Sep 03 09:19:49 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:49 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:49 volumio-rdc-dressing go-librespot[18469]: Librespot-go daemon starting... Sep 03 09:19:49 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:49+02:00" level=info msg="generated new device id: 42b2939201063c323d0503f7492efb8b01be7240" Sep 03 09:19:49 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:49+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:49 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="new websocket client" Sep 03 09:19:50 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="zeroconf server listening on port 44009" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="obtained new client token: AAB/slVistOR4bb7fg/27+95IGQ5LC/RHaml324njt6Czvo3H3Q/VYfX5sWHQ2IDEMs8xh/tfZLfrInw8ysjp2/EBUYlh9Uk12Qs7UAjD9CRCbaAvFSNK7+l3V/2nMQlbwnzkfzRHM44/ONHqdlt/FZlE+SsxzcDT3IZ0EZk1O3FFTk93FzQxZJ+Flw1uvAfnoB7YKiedV1sh23eqEDiOZG+Aj2Ktq9rU4SUTJkrAgPCDoh6VlL0jGOMpdY6fw==" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=debug msg="completed challenge" Sep 03 09:19:50 volumio-rdc-dressing go-librespot[18469]: time="2025-09-03T09:19:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:50 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:50 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:50 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: (node:887) 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: 4348) Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:53 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:54 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:54 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13429. Sep 03 09:19:54 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:54 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: Librespot-go daemon starting... Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: Received Get System Version Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: Received Get System Info Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: Discovery: Getting this device information Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=info msg="generated new device id: 0003bd70d3f3835be4e29b36cf73035939c3f154" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="zeroconf server listening on port 43757" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="obtained new client token: AADE+NH9ZXAog/4WMPeOrTI77tlRPRVFOLoaIDe/q+Lkysd5yWdto0djt1sobz9TzWdZnpbo3KBzQBTzSrmhkFBhZd77p+0bxHEU2SCK4rnyIIZAWD4NR+p+ozoaGJuKTt7ZzAEhAHaPZXoyZ5zAu0Fkb6cw0Ba+fYQBWi93QP42hJ1xUTVLmY0K/nWwBT9pg4yjbGCOi9MXejzQaY/eqIU2T7Msl0hOzbdPwMFDq/vveIBZmCcFARcjgcIMQw==" Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: Discovery: Getting this device information Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:54 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:54 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:54+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:55 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:55+02:00" level=debug msg="completed challenge" Sep 03 09:19:55 volumio-rdc-dressing go-librespot[18479]: time="2025-09-03T09:19:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:55 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:55 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:56 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:56 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:19:57 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:19:58 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:19:58 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13430. Sep 03 09:19:58 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:19:58 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: Librespot-go daemon starting... Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=info msg="generated new device id: 6dd12e3b17a9b087246f5bce219e1cc0e2fa1571" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: Discovery: Getting this device information Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:19:58 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="zeroconf server listening on port 44237" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="obtained new client token: AADeoK+0HgtEc2vJ563f7L1ym9CdvY1zwlHuNUcp1jOWM2uPhwZtZAESscKh7gB4mqNCmugJ+/VU/iHxZ2XuQB6YlnaAzcD/JDBBohFMYVIQk+1J4evgY+5/djjKIYVlE4oYDKgLTO+l/6PYMDSNtB5vCygj8Au7Knl8y7X+ZQYCo1AoLFddq0B/X6a4q0mLlV66kPetgPr9bk8G/2Lnj/LodBVBFwBxcgLjPPt693RnHQCzQgQcRP8KXk6mvw==" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:19:58 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:58+02:00" level=debug msg="completed keyexchange" Sep 03 09:19:59 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:59+02:00" level=debug msg="completed challenge" Sep 03 09:19:59 volumio-rdc-dressing go-librespot[18487]: time="2025-09-03T09:19:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:19:59 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:19:59 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:19:59 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:19:59 volumio-rdc-dressing volumio[887]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:20:02 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:20:02 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13431. Sep 03 09:20:02 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:20:02 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: Librespot-go daemon starting... Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=info msg="generated new device id: bd972f5473e68b00f40a0724d41df4f579c30441" Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:20:02 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:02+02:00" level=debug msg="zeroconf server listening on port 36383" Sep 03 09:20:02 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=debug msg="new websocket client" Sep 03 09:20:03 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=debug msg="obtained new client token: AACQj9a3aWOMQ4WQ9l0XDZ3dxr7oYuYjqRycLCCE0pl9VNsEQf+3Qx0E26RHiysxaWqEk6xvq4+c767RVPyqOpdu1dGLQZLwLTZYGhmhfWP7waZDS08O+7tYZjlBQ20BZIRdw5GqjfvmKwVCBDrFUEmMbaED2TAIo2HnVtOKNuqY5/N6gshRHoN8IA77+n8YE4oKn+L8GbHjRyXM5WG7fP6TB3y0kwmofZfCo5O09gFQ1+tKQot5xjFiq5o=" Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=debug msg="completed keyexchange" Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=debug msg="completed challenge" Sep 03 09:20:03 volumio-rdc-dressing go-librespot[18496]: time="2025-09-03T09:20:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:20:03 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:20:03 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:20:03 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:20:05 volumio-rdc-dressing volumio[887]: info: Discovery: Remote connection error: 10.0.0.2 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Getting Spotify volume Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: (node:887) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: (node:887) 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: 4349) Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Enabling I2S DAC: HiFiBerry DAC Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:06 volumio-rdc-dressing sudo[18505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Sep 03 09:20:06 volumio-rdc-dressing sudo[18505]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:20:06 volumio-rdc-dressing sudo[18505]: pam_unix(sudo:session): session closed for user root Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: No Overlays Loaded Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:06 volumio-rdc-dressing sudo[18508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dac Sep 03 09:20:06 volumio-rdc-dressing sudo[18508]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/#sound-dai-cells Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/compatible Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/status Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Sep 03 09:20:06 volumio-rdc-dressing kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Sep 03 09:20:06 volumio-rdc-dressing sudo[18508]: pam_unix(sudo:session): session closed for user root Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:06 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 03 09:20:06 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13432. Sep 03 09:20:06 volumio-rdc-dressing systemd[1]: Stopped go-librespot Daemon. Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Device 2 does not have any Mixer Control Available Sep 03 09:20:06 volumio-rdc-dressing systemd[1]: Started go-librespot Daemon. Sep 03 09:20:06 volumio-rdc-dressing go-librespot[18523]: Librespot-go daemon starting... Sep 03 09:20:06 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:06+02:00" level=info msg="generated new device id: 7de7c3b912aa7c59214446c72e678a24fb714e19" Sep 03 09:20:06 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:06+02:00" level=debug msg="stored credentials found for 21wbwoznfz7n3p6dzcixkfw2i" Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Disabling external Volume Control Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreStateMachine::pushState Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:06 volumio-rdc-dressing volumio[887]: info: Preparing to generate the ALSA configuration file Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Initializing connection to go-librespot Websocket Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Reading ALSA contributions from plugins. Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: [ASDebug] CurState: play PrevState: play Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: I2S Param [object Object] successfully enabled Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="new websocket client" Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket established Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="zeroconf server listening on port 37491" Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Getting Alsa Cards List without I2S DAC Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="obtained new client token: AADytrNKsl9if3rl06yDF5EZ/fFopfA1y1bwgkHzyy7CQwHGWP7F9w2SXwphEe82TTPTG54LJVhg+pafj5TVCMRrcGdSV96fStkZrqL+zoW+ySMPhCnUfo1g51rGLoYJ3maG7jmdOfCuZ8mC0EqHbQ8O4dMNUmnvvQN0d0su0q1FzBstyAzE65GUNsLAw0dlrjONlXP/Gta4SyjFHpPL+Fmyi95KSqlYZG3qsQd3guxRjoHXuXYSzMghe2c5VQ==" Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="completed keyexchange" Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Asound.conf file unchanged, so no further update is needed Sep 03 09:20:07 volumio-rdc-dressing volumio[887]: info: Output device has changed, restarting MPD Sep 03 09:20:07 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:07+02:00" level=debug msg="completed challenge" Sep 03 09:20:08 volumio-rdc-dressing go-librespot[18523]: time="2025-09-03T09:20:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 03 09:20:08 volumio-rdc-dressing sudo[18543]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 03 09:20:08 volumio-rdc-dressing sudo[18543]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: Output device has changed, restarting Shairport Sync Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing sudo[18543]: pam_unix(sudo:session): session closed for user root Sep 03 09:20:08 volumio-rdc-dressing sudo[18546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 03 09:20:08 volumio-rdc-dressing sudo[18546]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: Stopping Music Player Daemon... Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: MPD Permissions set Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: mpd.service: Succeeded. Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: Stopped Music Player Daemon. Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: Starting Music Player Daemon... Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: Connection to go-librespot Websocket closed Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 03 09:20:08 volumio-rdc-dressing volumio[887]: info: Starting Shairport Sync Sep 03 09:20:08 volumio-rdc-dressing sudo[18559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 03 09:20:08 volumio-rdc-dressing sudo[18559]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: shairport-sync.service: Succeeded. Sep 03 09:20:08 volumio-rdc-dressing systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 03 09:20:09 volumio-rdc-dressing systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 03 09:20:09 volumio-rdc-dressing sudo[18559]: pam_unix(sudo:session): session closed for user root Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: info: Shairport-Sync Started Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: info: PLUGIN onReboot : networkfs Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: info: PLUGIN onReboot : audiophonicsonoff Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: TypeError: Cannot read property 'writeSync' of undefined Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at CoreCommandRouter.reboot (/volumio/app/index.js:1324:22) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:836:33) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at Socket.emit (events.js:315:20) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Sep 03 09:20:09 volumio-rdc-dressing volumio[887]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 09:20:10 volumio-rdc-dressing sudo[18577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-03 09:19 Sep 03 09:20:10 volumio-rdc-dressing sudo[18577]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"