-- Logs begin at Sat 2025-07-05 06:57:01 +07, end at Sat 2025-07-05 09:34:40 +07. -- Jul 05 09:33:00 volumio2 go-librespot[15288]: time="2025-07-05T09:33:00+07:00" level=debug msg="completed challenge" Jul 05 09:33:00 volumio2 go-librespot[15288]: time="2025-07-05T09:33:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:00 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:00 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:01 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:01 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:03 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:03 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10734. Jul 05 09:33:03 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:03 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:03 volumio2 go-librespot[15303]: Librespot-go daemon starting... Jul 05 09:33:03 volumio2 go-librespot[15303]: time="2025-07-05T09:33:03+07:00" level=info msg="generated new device id: 19ecb31381f380bee66528864434b979e8f17bf1" Jul 05 09:33:03 volumio2 go-librespot[15303]: time="2025-07-05T09:33:03+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:03 volumio2 go-librespot[15303]: time="2025-07-05T09:33:03+07:00" level=debug msg="obtained new client token: AAC/EoFqHm/VzEbIx51GmXWXqanNFRMpRyxoJ9SzRCR55CRMM2t9/RV8c6yjhh6Wbtxx2e2qTRcZP98XqvYKEKznHNIQRl6dXv67NQu7N51lDr6/1PliCi16nuV2YkJpPx/zzZ+NhIXD9E1FiHcJ+C9Rq5UZv6Js9Ik/fJZnB4/xFcM5yDqmRp6duaeMeF/H5OhaGOZKx75TwzS8yPQgWLMQfRL8J5i6hc0YPvMbEpihP2FKL+7k+3sTCzzv" Jul 05 09:33:03 volumio2 go-librespot[15303]: time="2025-07-05T09:33:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:03 volumio2 go-librespot[15303]: time="2025-07-05T09:33:03+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:04 volumio2 go-librespot[15303]: time="2025-07-05T09:33:04+07:00" level=debug msg="completed challenge" Jul 05 09:33:04 volumio2 go-librespot[15303]: time="2025-07-05T09:33:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:04 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:04 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:04 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:04 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:07 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:07 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:07 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:07 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10735. Jul 05 09:33:07 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:07 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:07 volumio2 go-librespot[15332]: Librespot-go daemon starting... Jul 05 09:33:07 volumio2 go-librespot[15332]: time="2025-07-05T09:33:07+07:00" level=info msg="generated new device id: 0b33bef4a6d85071936c01c5aee4461eee3885e5" Jul 05 09:33:07 volumio2 go-librespot[15332]: time="2025-07-05T09:33:07+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:07 volumio2 go-librespot[15332]: time="2025-07-05T09:33:07+07:00" level=debug msg="obtained new client token: AABhOwTSqZzYz6ZQ/xh/e51mcrq2rRiHKDTJyCUY+h0JTJ+IFkGC0oUfYRK2SFUm2nL7CPdsA93Ni1+WH0BzlR3A4JghbTn4a4r6cnwW7dCuz3KCszMrCS2jOjX7Bw1gK8JXvFLwn30TCvf4mOLIOiv3CqWY7Hs0JmCA9oQkqX5t6AZdVx0kB9gOAPKcHZC1UJH7cGV6svqfUWrge05P+pWZqbNvUs72tWOePfIwkHs1epcQC+pDtTFSBj2n" Jul 05 09:33:07 volumio2 go-librespot[15332]: time="2025-07-05T09:33:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:07 volumio2 go-librespot[15332]: time="2025-07-05T09:33:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 09:33:07 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:07 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:10 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:10 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:10 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:10 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10736. Jul 05 09:33:10 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:10 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:10 volumio2 go-librespot[15349]: Librespot-go daemon starting... Jul 05 09:33:10 volumio2 go-librespot[15349]: time="2025-07-05T09:33:10+07:00" level=info msg="generated new device id: ee605b5cf18d3231ae24bee085b9203ed1a7a2b2" Jul 05 09:33:10 volumio2 go-librespot[15349]: time="2025-07-05T09:33:10+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:10 volumio2 go-librespot[15349]: time="2025-07-05T09:33:10+07:00" level=debug msg="obtained new client token: AAAHKD7pdv5dEITWCiv6Ap2OsZBX4U0yUG7W8W5jsIk83HyEwF8zpDlzsQDRkeISFntxsgdct5V55e7y77WZg7p9IIYKWtBuOXy4zJKIs6XaMLPp4Sgyq0wNs56Mg3Aws/UTX4OG76ZSN89J0aunvgfW5VrDqwETqYZYAuixqMgL5MeLKJn0s55DeLbksQwWsGJZZYojvhpodf8lQ0dErjZx0B7P5bEj285ovTeWwJCBpagsM/kD6kN02Otq" Jul 05 09:33:11 volumio2 go-librespot[15349]: time="2025-07-05T09:33:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:11 volumio2 go-librespot[15349]: time="2025-07-05T09:33:11+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:11 volumio2 go-librespot[15349]: time="2025-07-05T09:33:11+07:00" level=debug msg="completed challenge" Jul 05 09:33:11 volumio2 go-librespot[15349]: time="2025-07-05T09:33:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:11 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:11 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:13 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:13 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:14 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:14 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10737. Jul 05 09:33:14 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:14 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:14 volumio2 go-librespot[15424]: Librespot-go daemon starting... Jul 05 09:33:14 volumio2 go-librespot[15424]: time="2025-07-05T09:33:14+07:00" level=info msg="generated new device id: e398c81c1c6c5987a4ec2018b371bed00d151452" Jul 05 09:33:14 volumio2 go-librespot[15424]: time="2025-07-05T09:33:14+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:15 volumio2 go-librespot[15424]: time="2025-07-05T09:33:15+07:00" level=debug msg="obtained new client token: AAD3AHMa9Lm0/nuKOOF/JEWvRg95/LNCPacAeErv0Zv6BKGQ/1dWn2qY0ncubvvihIoOknGmOVwR2E8XM6yhoxtuBc+hq4BvU9xeYiIFqPz4y0PXvJzVErplpM3NrDR8NgBlbKt4E9HVo9fiiWI7UdfXn5JPLLGFaGntSl5UL02PkQJvXhTrKjztUuo30Lw3JRvtnc/O/kkb9MOqNR3y0Yie9Lf0ePQrLDMsAgedpR2799oORc76fG8qFw==" Jul 05 09:33:15 volumio2 go-librespot[15424]: time="2025-07-05T09:33:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:15 volumio2 go-librespot[15424]: time="2025-07-05T09:33:15+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:15 volumio2 go-librespot[15424]: time="2025-07-05T09:33:15+07:00" level=debug msg="completed challenge" Jul 05 09:33:15 volumio2 go-librespot[15424]: time="2025-07-05T09:33:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:15 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:15 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:16 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:16 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:18 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:18 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10738. Jul 05 09:33:18 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:18 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:18 volumio2 go-librespot[15442]: Librespot-go daemon starting... Jul 05 09:33:18 volumio2 go-librespot[15442]: time="2025-07-05T09:33:18+07:00" level=info msg="generated new device id: 4d55fa3778ed33986f05ed1c06071b1ef1b95337" Jul 05 09:33:18 volumio2 go-librespot[15442]: time="2025-07-05T09:33:18+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:19 volumio2 go-librespot[15442]: time="2025-07-05T09:33:19+07:00" level=debug msg="obtained new client token: AABEU0fQ7Qag2dxxe+71deUUq5MaAgjcVBp1YYapE9cq1ge7lM/NKssnGXVJQmqB+eBHdoOMsQx3Eq3l4VsGIZ4vfWdEk0yOnHsKHhaLu/fJlT9WjCqnxPIJToK6S/vtbRKD0Rv9ECidmlhWWRYCCc/laiphSPKb+NVo+h0EiCRybON65eeVfNrRIQfSXx+9CqEaOdKqrg7wyRgByr1Syv3csREKDXnOsNfurfcDOXGHE0kQ+LusB7ubDg==" Jul 05 09:33:19 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:19 volumio2 go-librespot[15442]: time="2025-07-05T09:33:19+07:00" level=debug msg="new websocket client" Jul 05 09:33:19 volumio2 volumio[1040]: info: Connection to go-librespot Websocket established Jul 05 09:33:19 volumio2 go-librespot[15442]: time="2025-07-05T09:33:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:19 volumio2 go-librespot[15442]: time="2025-07-05T09:33:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 09:33:19 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:19 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:19 volumio2 volumio[1040]: info: Connection to go-librespot Websocket closed Jul 05 09:33:22 volumio2 volumio[1040]: info: Getting Spotify volume Jul 05 09:33:22 volumio2 volumio[1040]: (node:1040) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:22 volumio2 volumio[1040]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 09:33:22 volumio2 volumio[1040]: (node:1040) 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: 1392) Jul 05 09:33:22 volumio2 volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 05 09:33:22 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:33:22 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:22 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:22 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:22 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:22 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10739. Jul 05 09:33:22 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:22 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:22 volumio2 go-librespot[15456]: Librespot-go daemon starting... Jul 05 09:33:22 volumio2 go-librespot[15456]: time="2025-07-05T09:33:22+07:00" level=info msg="generated new device id: 18ec42e2eec9976482218c78d61345334b59749a" Jul 05 09:33:22 volumio2 go-librespot[15456]: time="2025-07-05T09:33:22+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:22 volumio2 go-librespot[15456]: time="2025-07-05T09:33:22+07:00" level=debug msg="obtained new client token: AACJuscUoQLFTaBVxR6IMUOeiYV4/tS3fPfUmw8z3RkY2iHluCy/zd64y1ZByLXxzVRDZTwfvQNFQmwWi6qV3vtlN3j561Y5WeVKQoruV2QNs9x03x2SwyjXkkZbFXlqo5e3z8Ui7gGyETuVDPCpTxpCGsYYX9x147CKkyFiWXnAvE778lKwL8ttwH7r3IxtlYVSgdEF9uZqs0LHQdPuZEcFnhRn1xRqjVk4ybJA6yHoBCch+qslA+spAqZR" Jul 05 09:33:22 volumio2 go-librespot[15456]: time="2025-07-05T09:33:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:22 volumio2 go-librespot[15456]: time="2025-07-05T09:33:22+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:23 volumio2 go-librespot[15456]: time="2025-07-05T09:33:23+07:00" level=debug msg="completed challenge" Jul 05 09:33:23 volumio2 go-librespot[15456]: time="2025-07-05T09:33:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:23 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:23 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:25 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:25 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:26 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:26 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10740. Jul 05 09:33:26 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:26 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:26 volumio2 go-librespot[15486]: Librespot-go daemon starting... Jul 05 09:33:26 volumio2 go-librespot[15486]: time="2025-07-05T09:33:26+07:00" level=info msg="generated new device id: d2a5413a24df818245bef24856d5b1f7f1b9aac3" Jul 05 09:33:26 volumio2 go-librespot[15486]: time="2025-07-05T09:33:26+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:26 volumio2 go-librespot[15486]: time="2025-07-05T09:33:26+07:00" level=debug msg="obtained new client token: AAChQHBH3mZItBxD+lvsYmY8vp5JQRVsPy/3JTkqfuvKpBGUm403rGZ0rh2sDSncUyq75xFAIRNYwAQUbucKSmrxAgQ4yw8d6wdnXwm3OnUBPRwTuhPB7c0sJTkCGw6XbST2rGXn2ewZ5ZI9uKRSnTcuvGBnc9C98A/M//dunx2Xugy0skhBwu+S+UY/ks8y6sMSHJB8ycfD9Hvuom51cpUzmdskwOGnsmCfPnswsV4m36YewuPj7av9jUwO" Jul 05 09:33:26 volumio2 go-librespot[15486]: time="2025-07-05T09:33:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:33:26 volumio2 go-librespot[15486]: time="2025-07-05T09:33:26+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:27 volumio2 go-librespot[15486]: time="2025-07-05T09:33:27+07:00" level=debug msg="completed challenge" Jul 05 09:33:27 volumio2 go-librespot[15486]: time="2025-07-05T09:33:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:27 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:27 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:28 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:28 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:29 volumio2 volumio[1040]: info: Jul 05 09:33:29 volumio2 volumio[1040]: ---------------------------- MPD announces state update: player Jul 05 09:33:29 volumio2 volumio[1040]: info: ControllerMpd::getState Jul 05 09:33:29 volumio2 volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Jul 05 09:33:29 volumio2 volumio[1040]: info: Jul 05 09:33:29 volumio2 volumio[1040]: ---------------------------- MPD announces state update: player Jul 05 09:33:29 volumio2 volumio[1040]: info: ControllerMpd::getState Jul 05 09:33:29 volumio2 volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Jul 05 09:33:29 volumio2 volumio[1040]: info: sendMpdCommand status took 0 milliseconds Jul 05 09:33:29 volumio2 volumio[1040]: verbose: ControllerMpd::parseState Jul 05 09:33:29 volumio2 volumio[1040]: info: ControllerMpd::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::servicePushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioPushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CorePlayQueue::getTrack 0 Jul 05 09:33:29 volumio2 volumio[1040]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 05 09:33:29 volumio2 volumio[1040]: verbose: CURRENT POSITION 0 Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::syncState stateService stop Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::syncState currentStatus play Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioPushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::stPlaybackTimer Jul 05 09:33:29 volumio2 volumio[1040]: info: ------------------------------ 5ms Jul 05 09:33:29 volumio2 volumio[1040]: info: sendMpdCommand status took 5 milliseconds Jul 05 09:33:29 volumio2 volumio[1040]: verbose: ControllerMpd::parseState Jul 05 09:33:29 volumio2 volumio[1040]: info: ControllerMpd::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::servicePushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioPushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CorePlayQueue::getTrack 0 Jul 05 09:33:29 volumio2 volumio[1040]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 05 09:33:29 volumio2 volumio[1040]: verbose: CURRENT POSITION 0 Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::syncState stateService stop Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioPushState Jul 05 09:33:29 volumio2 volumio[1040]: info: No code Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::pushState Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioPushState Jul 05 09:33:29 volumio2 volumio[1040]: info: ------------------------------ 13ms Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetQueue Jul 05 09:33:29 volumio2 volumio[1040]: info: CoreStateMachine::getQueue Jul 05 09:33:29 volumio2 volumio[1040]: info: CorePlayQueue::getQueue Jul 05 09:33:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:33:30 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:30 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10741. Jul 05 09:33:30 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:30 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:30 volumio2 go-librespot[15503]: Librespot-go daemon starting... Jul 05 09:33:30 volumio2 go-librespot[15503]: time="2025-07-05T09:33:30+07:00" level=info msg="generated new device id: 61be79c55133555978653792cfda9ec7d3e5603e" Jul 05 09:33:30 volumio2 go-librespot[15503]: time="2025-07-05T09:33:30+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:30 volumio2 go-librespot[15503]: time="2025-07-05T09:33:30+07:00" level=debug msg="obtained new client token: AAAU9ytByce5x+hj+epEKEbmfxOuVtrJUm6nxaooMG4B4ZEHsQLM0gbmHHYhzgoak88zHRCSY1wwvlzEtR81Xu08Tthdx2HdOhx3jeeFzjTODkxTw7dDjZvKKIrSvaiQhtjHecKlG1FzLPOii31a6ya3OanCjwPw8UYbtblHNBBN/y/xj5f0n2tk4vwomGKv7ToJ5kKzgyz6Njcl8KduhG70888RT0NP2/QfjjXJf8xK6hGYiso0OPrCHOdn" Jul 05 09:33:30 volumio2 go-librespot[15503]: time="2025-07-05T09:33:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:30 volumio2 go-librespot[15503]: time="2025-07-05T09:33:30+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:31 volumio2 go-librespot[15503]: time="2025-07-05T09:33:31+07:00" level=debug msg="completed challenge" Jul 05 09:33:31 volumio2 go-librespot[15503]: time="2025-07-05T09:33:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:31 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:31 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:31 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:31 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:34 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:34 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:34 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:34 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10742. Jul 05 09:33:34 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:34 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:34 volumio2 go-librespot[15518]: Librespot-go daemon starting... Jul 05 09:33:34 volumio2 go-librespot[15518]: time="2025-07-05T09:33:34+07:00" level=info msg="generated new device id: 85849b93fc3b71524d39ba461d3b817a258a3f8d" Jul 05 09:33:34 volumio2 go-librespot[15518]: time="2025-07-05T09:33:34+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:34 volumio2 go-librespot[15518]: time="2025-07-05T09:33:34+07:00" level=debug msg="obtained new client token: AABKG+0BvaMR8DsGo4duZnAaGSc9OaV7HDdLPBRcjBA6zsxZPUTfvVxjle8fV5BfSSc5Iodw9SmlZ/GC5k0ADC2hgnCAl8lC8m7Z0i25rON1Hk7qw2mWpHPElxszy0WiXb+wLhMHhy1IazLLoQE26eMUQvYKA9SKolU8fIw2+GjFLEt/HukOOCex0s1s3c5d9o1z/v/MgfhH/EOef0zRSSdfZX3+2dM7mWepaCvfPgTywydYcYIv6yuWukU0" Jul 05 09:33:34 volumio2 go-librespot[15518]: time="2025-07-05T09:33:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:34 volumio2 go-librespot[15518]: time="2025-07-05T09:33:34+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:35 volumio2 go-librespot[15518]: time="2025-07-05T09:33:35+07:00" level=debug msg="completed challenge" Jul 05 09:33:35 volumio2 go-librespot[15518]: time="2025-07-05T09:33:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:35 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:35 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:37 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:37 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:38 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:38 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10743. Jul 05 09:33:38 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:38 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:38 volumio2 go-librespot[15549]: Librespot-go daemon starting... Jul 05 09:33:38 volumio2 go-librespot[15549]: time="2025-07-05T09:33:38+07:00" level=info msg="generated new device id: d89406ad8ca95f16978cb0919d17f07a783dcf57" Jul 05 09:33:38 volumio2 go-librespot[15549]: time="2025-07-05T09:33:38+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:38 volumio2 go-librespot[15549]: time="2025-07-05T09:33:38+07:00" level=debug msg="obtained new client token: AAAxEqgJUAQYnU9S8+koMSmPQy3TzY2OKlNNxE88V2f0JfaSJwC65eNkxGKq1u0MNXQSASd6lqk8rZGbXPkPV0Dk4pFLenrmbwL47OHKDKyuMEI5rM+OE1LvlUMnQ74cOO0IgbbPHu87PqGDZ70PWjKBNa4W3974edBymDs43CEFhW52SZENFNB7sI9oOZnukyT1gGt/vyTuAYtxxGsvq3/UIjfH5OpYOAkzd8pERBcAXZQwYxjNruyQ1qty" Jul 05 09:33:38 volumio2 go-librespot[15549]: time="2025-07-05T09:33:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:38 volumio2 go-librespot[15549]: time="2025-07-05T09:33:38+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:39 volumio2 go-librespot[15549]: time="2025-07-05T09:33:39+07:00" level=debug msg="completed challenge" Jul 05 09:33:39 volumio2 go-librespot[15549]: time="2025-07-05T09:33:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:39 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:39 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:40 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:40 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:42 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:42 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10744. Jul 05 09:33:42 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:42 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:42 volumio2 go-librespot[15567]: Librespot-go daemon starting... Jul 05 09:33:42 volumio2 go-librespot[15567]: time="2025-07-05T09:33:42+07:00" level=info msg="generated new device id: 2e2a749556434d274622448828f1ddf5eca9c0a4" Jul 05 09:33:42 volumio2 go-librespot[15567]: time="2025-07-05T09:33:42+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:42 volumio2 go-librespot[15567]: time="2025-07-05T09:33:42+07:00" level=debug msg="obtained new client token: AAD3NPWj+ai0Gje4QMzTDqI9TDbYh3NZBAeABcuWQb/BrQ0P3ofFgGHJN4JilnjiIHaJXHlRv3ZjayIpXw91suBKzXrTPXvnmaYUA0dvYpCW5ldiyNCbUuWTiVjPTdVd5Av0NXkVNAkofD6ivBpzcvFDLqUmr9Req7gxN6EzYZyNz4joiiz9Eo2sOaQ+ynYIIAzM/wyFvo7i2jhtomcQGkxv1h/lWWBdFf+hhdwXVxcUsD9ZvM6PPAm7LhOE" Jul 05 09:33:42 volumio2 go-librespot[15567]: time="2025-07-05T09:33:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:42 volumio2 go-librespot[15567]: time="2025-07-05T09:33:42+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:43 volumio2 go-librespot[15567]: time="2025-07-05T09:33:43+07:00" level=debug msg="completed challenge" Jul 05 09:33:43 volumio2 go-librespot[15567]: time="2025-07-05T09:33:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:43 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:43 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:43 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:43 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:46 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:46 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:46 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:46 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10745. Jul 05 09:33:46 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:46 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:46 volumio2 go-librespot[15597]: Librespot-go daemon starting... Jul 05 09:33:46 volumio2 go-librespot[15597]: time="2025-07-05T09:33:46+07:00" level=info msg="generated new device id: 766cb87b3c856c155cba31da9229d4db3b11097a" Jul 05 09:33:46 volumio2 go-librespot[15597]: time="2025-07-05T09:33:46+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:46 volumio2 go-librespot[15597]: time="2025-07-05T09:33:46+07:00" level=debug msg="obtained new client token: AAA31seYHr3JLqRuBphVOn19iHbKMjf39c2TkOOP55hTlKIAXxNmn0gKZ2HBgUrfuRY8ZHBenGQvmJryW1yqlhJDWh/E97huVBVx1MxzZ+C7h9TAhilm0CYa/HN/eKQ78hJY+99hQxcljhRZS63bhsGHBBs192Q1nPphHkNE1VHyhZqysFfxUkiBxy/FRu05uUCM8062Rcv/oKfsw53unN6VWoSdXOXMXV+W7KfTSMCZXu08yjW3yxkbQ9j4" Jul 05 09:33:46 volumio2 go-librespot[15597]: time="2025-07-05T09:33:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:33:46 volumio2 go-librespot[15597]: time="2025-07-05T09:33:46+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:47 volumio2 go-librespot[15597]: time="2025-07-05T09:33:47+07:00" level=debug msg="completed challenge" Jul 05 09:33:47 volumio2 go-librespot[15597]: time="2025-07-05T09:33:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:47 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:47 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:49 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:49 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:50 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:50 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10746. Jul 05 09:33:50 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:50 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:50 volumio2 go-librespot[15614]: Librespot-go daemon starting... Jul 05 09:33:50 volumio2 go-librespot[15614]: time="2025-07-05T09:33:50+07:00" level=info msg="generated new device id: c288145ddce2f4e353d2f6c2d1eb177fd0579bcb" Jul 05 09:33:50 volumio2 go-librespot[15614]: time="2025-07-05T09:33:50+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:50 volumio2 go-librespot[15614]: time="2025-07-05T09:33:50+07:00" level=debug msg="obtained new client token: AABkzytkiasMgdpMNiySd9HIUgL7AtclJ33Gs9OM1SRDMa3HQGD+3NUAAlbyo5auFBbldbOBCZj5xhRaQ46clWfveMBgzUrYvaUjMX7mxQ6z/7Ak+kGkAuh222W9ffMNz9tFvtKNSQVf4PciC2i6HXRMLY4ytvh9g9p42ab2h6WXGFW5Ou5uyxEsoGCDSAKDAHmbVTYpFl62hrqM0nCkUM8SlUpX9nbtgbBL3JptFYU0b1huNFx0OOUd0F6Z" Jul 05 09:33:50 volumio2 go-librespot[15614]: time="2025-07-05T09:33:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:33:50 volumio2 go-librespot[15614]: time="2025-07-05T09:33:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 09:33:50 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:50 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:52 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:52 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:53 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:53 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10747. Jul 05 09:33:53 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:53 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:53 volumio2 go-librespot[15630]: Librespot-go daemon starting... Jul 05 09:33:53 volumio2 go-librespot[15630]: time="2025-07-05T09:33:53+07:00" level=info msg="generated new device id: 0a5926f90b1a7495290eb416999cabbdcd4ab4a7" Jul 05 09:33:53 volumio2 go-librespot[15630]: time="2025-07-05T09:33:53+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:54 volumio2 go-librespot[15630]: time="2025-07-05T09:33:54+07:00" level=debug msg="obtained new client token: AAAkiQNeqHuwIkta3cqnfX1CCxYm1Zah09mpsruZgwlS1/PsKt7DawKGIwUGUx5YuVhINvAO/qEeMA6A6WOoODUc5SU99qWtlo+Hpp1C3dTmdQCDLh72D9jxGo4QYxwvWZS4qLDmnr0+N1n0HwTphNCUWSr7n4ABkvTXUBZiAPY6OeU43uNT5TlwHaj5WD3AF7VnaojpwfCOEJ6StSXpez1V7yFNc54VxLN2wfJeyBHV6Wz0Kz3jbDos+A==" Jul 05 09:33:54 volumio2 go-librespot[15630]: time="2025-07-05T09:33:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:33:54 volumio2 go-librespot[15630]: time="2025-07-05T09:33:54+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:54 volumio2 go-librespot[15630]: time="2025-07-05T09:33:54+07:00" level=debug msg="completed challenge" Jul 05 09:33:54 volumio2 go-librespot[15630]: time="2025-07-05T09:33:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:54 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:54 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:33:55 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:55 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:33:57 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:33:57 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10748. Jul 05 09:33:57 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:33:57 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:33:57 volumio2 go-librespot[15660]: Librespot-go daemon starting... Jul 05 09:33:57 volumio2 go-librespot[15660]: time="2025-07-05T09:33:57+07:00" level=info msg="generated new device id: 0dfcec80429b4afa8766344ddce69d194331e0fe" Jul 05 09:33:57 volumio2 go-librespot[15660]: time="2025-07-05T09:33:57+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=debug msg="obtained new client token: AABq9A1I4f45Ab4nRaqgUNOOQYn0aW5tXIOfRGQVxsD1zVCqBeR6Rcp8wGLebgxk4s8W7oUN64Fb03hyakOcattR11gHat5tONqpFQf160LnBZrIlVAHIJWJCQ59ACL7MPjqQdXy/8ZkfW77e0Oo2+fLFTctdeK28uzX4LVHtMfKdS/DUUCwD2+GUQnHzRSWaeOGMI2FaQ7F3qocnkbHTsFTK+3lNB5HBfEN2kzULrVoXmgJv+vyW8wo4Q==" Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=debug msg="completed keyexchange" Jul 05 09:33:58 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=debug msg="new websocket client" Jul 05 09:33:58 volumio2 volumio[1040]: info: Connection to go-librespot Websocket established Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=debug msg="completed challenge" Jul 05 09:33:58 volumio2 go-librespot[15660]: time="2025-07-05T09:33:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:33:58 volumio2 volumio[1040]: info: Connection to go-librespot Websocket closed Jul 05 09:33:58 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:33:58 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:01 volumio2 volumio[1040]: info: Getting Spotify volume Jul 05 09:34:01 volumio2 volumio[1040]: (node:1040) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:01 volumio2 volumio[1040]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 09:34:01 volumio2 volumio[1040]: (node:1040) 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: 1393) Jul 05 09:34:01 volumio2 volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 05 09:34:01 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:01 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:34:01 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:01 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:01 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:01 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10749. Jul 05 09:34:01 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:01 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:01 volumio2 go-librespot[15678]: Librespot-go daemon starting... Jul 05 09:34:01 volumio2 go-librespot[15678]: time="2025-07-05T09:34:01+07:00" level=info msg="generated new device id: 32da350e2924cde18a4024f84738c786022de9a4" Jul 05 09:34:01 volumio2 go-librespot[15678]: time="2025-07-05T09:34:01+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:02 volumio2 go-librespot[15678]: time="2025-07-05T09:34:02+07:00" level=debug msg="obtained new client token: AADNTN7HWFMSr18Xs69FW2VmEPPmqSfQeVqkVyA8G5jibihWpTW0jz/myfvZNVaz75uO5w9eqM8fXmhHdwhw6SYwKD9ipR1wrJ1mSqufRaiZuxlFevdAkD9DziXcW7gjmjktYu5T1TrPkjtdivPXQo4GrtkCV+nlHZxMazCCFkQTBE1LUh7UNT7ULIcN2ED/moPgkdkTWiEZOyJGCgmTNMZXlnYQ0tb6Ee6BYTm+L3mBkwiOur6gU4rlng==" Jul 05 09:34:02 volumio2 go-librespot[15678]: time="2025-07-05T09:34:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:02 volumio2 go-librespot[15678]: time="2025-07-05T09:34:02+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:02 volumio2 go-librespot[15678]: time="2025-07-05T09:34:02+07:00" level=debug msg="completed challenge" Jul 05 09:34:02 volumio2 go-librespot[15678]: time="2025-07-05T09:34:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:02 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:02 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:03 volumio2 volumio[1040]: error: Upnp client error: Error: This socket has been ended by the other party Jul 05 09:34:04 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:04 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:06 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:06 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10750. Jul 05 09:34:06 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:06 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:06 volumio2 go-librespot[15703]: Librespot-go daemon starting... Jul 05 09:34:06 volumio2 go-librespot[15703]: time="2025-07-05T09:34:06+07:00" level=info msg="generated new device id: fe02e5228935642a9d1b3c3e6113b2c62ca68b6d" Jul 05 09:34:06 volumio2 go-librespot[15703]: time="2025-07-05T09:34:06+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:06 volumio2 go-librespot[15703]: time="2025-07-05T09:34:06+07:00" level=debug msg="obtained new client token: AABDFolXMQ90wSgVOP+/ngI9R/dwcg59kHzVaDlVvWxkYDUxI+cckJHjRCk9VccVaYR1B6Fl1ZddyMnqeJIn5kkEEY9a8WbbTjV7X2z9mLzILhEdtq3oY8VJpyg7JMAr/JR8E3D3EZp8vsw9Wm9Xc/cCmOs7oWkUKrP38NSujmSqBOgy0sQ/5oNGuphJVb3P6Q7Ed9ACXeDGS33FJl9nZ5pQcTTNgOhQoXIwlUG4YYlSZHYV1C2CdojxRDnL" Jul 05 09:34:06 volumio2 go-librespot[15703]: time="2025-07-05T09:34:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:34:06 volumio2 go-librespot[15703]: time="2025-07-05T09:34:06+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:07 volumio2 go-librespot[15703]: time="2025-07-05T09:34:07+07:00" level=debug msg="completed challenge" Jul 05 09:34:07 volumio2 go-librespot[15703]: time="2025-07-05T09:34:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:07 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:07 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:07 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:07 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:10 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:10 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10751. Jul 05 09:34:10 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:10 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:10 volumio2 go-librespot[15712]: Librespot-go daemon starting... Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=info msg="generated new device id: 238f3d57358fe5f5d098b3a560b3505d879c52f7" Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=debug msg="obtained new client token: AAA7WEBVzLA0pmy1gZLsNnwA+IvLDpghrapGSe6CTJ2JJbx1aoPAnxn6ufaBNJZ4KJhsTUsmOeTjmIkpcdEOQDx3VXarjkafRezadofRh4fcLJQp0njMKnFbVa8T5uwe1PuBDSj44+E1uvQ59Wn5MrvpxsXanWT8fH3kOazpkOV3h1JhfJA+8tQfqA6+z6LBomOygO8P0TuLry99vf0YII1Qt93ELa4MT7DTri5QZXOILnHuIWrDeF5XUvql" Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:10 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:10 volumio2 go-librespot[15712]: time="2025-07-05T09:34:10+07:00" level=debug msg="new websocket client" Jul 05 09:34:10 volumio2 volumio[1040]: info: Connection to go-librespot Websocket established Jul 05 09:34:11 volumio2 go-librespot[15712]: time="2025-07-05T09:34:11+07:00" level=debug msg="completed challenge" Jul 05 09:34:11 volumio2 go-librespot[15712]: time="2025-07-05T09:34:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:11 volumio2 volumio[1040]: info: Connection to go-librespot Websocket closed Jul 05 09:34:11 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:11 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:13 volumio2 volumio[1040]: info: Getting Spotify volume Jul 05 09:34:13 volumio2 volumio[1040]: (node:1040) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:13 volumio2 volumio[1040]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 09:34:13 volumio2 volumio[1040]: (node:1040) 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: 1394) Jul 05 09:34:13 volumio2 volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 05 09:34:13 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:13 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:34:14 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:14 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:14 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:14 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10752. Jul 05 09:34:14 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:14 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:14 volumio2 go-librespot[15763]: Librespot-go daemon starting... Jul 05 09:34:14 volumio2 go-librespot[15763]: time="2025-07-05T09:34:14+07:00" level=info msg="generated new device id: 3875588186beec3d0e416156b571731d3481b256" Jul 05 09:34:14 volumio2 go-librespot[15763]: time="2025-07-05T09:34:14+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:14 volumio2 go-librespot[15763]: time="2025-07-05T09:34:14+07:00" level=debug msg="obtained new client token: AAAw6hFiB+8VplIWJwT4QbJW+W7jOwXX/opD/kd77nlQV7xDlG9aJS8abz0neALUIHlqFkZ7X/Dz3Gz8EIoNXn5wWwKK3TCVKMlwQ+hLwYhxXjCTY0htZhHOFJs0FSv0Uumq9sy+H0chs8nx8WxJ4blQ563o2LKIyJtCzPMhB4lIFYIRZa0UW3nAS4An0P9MKDxcO8W0O7eEORZIQogsINCsVy0SaYNc00kVQhIln2dHDU868ggBDC4AkVG6" Jul 05 09:34:14 volumio2 go-librespot[15763]: time="2025-07-05T09:34:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 09:34:14 volumio2 go-librespot[15763]: time="2025-07-05T09:34:14+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:15 volumio2 go-librespot[15763]: time="2025-07-05T09:34:15+07:00" level=debug msg="completed challenge" Jul 05 09:34:15 volumio2 go-librespot[15763]: time="2025-07-05T09:34:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:15 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:15 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:17 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:17 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:18 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:18 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10753. Jul 05 09:34:18 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:18 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:18 volumio2 go-librespot[15785]: Librespot-go daemon starting... Jul 05 09:34:18 volumio2 go-librespot[15785]: time="2025-07-05T09:34:18+07:00" level=info msg="generated new device id: 9005d68b6f14b056dcc604c1d4156c24b56f89d4" Jul 05 09:34:18 volumio2 go-librespot[15785]: time="2025-07-05T09:34:18+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:18 volumio2 go-librespot[15785]: time="2025-07-05T09:34:18+07:00" level=debug msg="obtained new client token: AADZk5tvYRW6m07Wfv8fchTovMeL7bEUR1CV6S+Ru71Rf1Eo0HVylarTrpqGl7E8W9gf1faRrMcHRdS/HDt4PmLB5nbB45Np20XUTMdNiQYIqDhrI82SbxSkUKeuxQbPvMCthj5wlHXu86hkXqkpRz8dQff8awzTqyncfLW42FwSsvEjJQ4DJFNr7xnUfofm5L8yLrIhhJc08RL3G6jxl7R1hC2d99NBqDqVvzPuW8GXErjDZ12+2iD6fj63" Jul 05 09:34:18 volumio2 go-librespot[15785]: time="2025-07-05T09:34:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:19 volumio2 go-librespot[15785]: time="2025-07-05T09:34:19+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:19 volumio2 go-librespot[15785]: time="2025-07-05T09:34:19+07:00" level=debug msg="completed challenge" Jul 05 09:34:19 volumio2 go-librespot[15785]: time="2025-07-05T09:34:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:19 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:19 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:20 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:20 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 09:34:22 volumio2 volumio[1040]: info: Discovery: Getting this device information Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 09:34:22 volumio2 volumio[1040]: verbose: New Socket.io Connection to 192.168.1.43:3000 from 192.168.1.20 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 09:34:22 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 09:34:22 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:22 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10754. Jul 05 09:34:22 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:22 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:22 volumio2 go-librespot[15799]: Librespot-go daemon starting... Jul 05 09:34:22 volumio2 go-librespot[15799]: time="2025-07-05T09:34:22+07:00" level=info msg="generated new device id: cc65c42233a8aa51c2d905e76655bc39256d14a6" Jul 05 09:34:22 volumio2 go-librespot[15799]: time="2025-07-05T09:34:22+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:22 volumio2 go-librespot[15799]: time="2025-07-05T09:34:22+07:00" level=debug msg="obtained new client token: AABP0AzO9ya2sK0JKlPeB0TIS9r/2UzCE5pUYmqO81sdS5X/jPx/i3k3j/OVwrnJ2XPJBK3d2ndhSxnpXr+nKqpIqMBVcP+PBhreE4ScoLTE9eBbYn0g+sRL49r37DLHo+Pwbt+oIWwqc5Ul2TnPjuhUH83HAeDmZzg7C3yIxLIeIeNWVYkN+FbVXHBcEadFwKYrFxWJr0iTc8e4SyfYKgQnmF0i9nCenyZyZREhz+bg/P9nC8NAv/9oMRIS" Jul 05 09:34:22 volumio2 go-librespot[15799]: time="2025-07-05T09:34:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:23 volumio2 go-librespot[15799]: time="2025-07-05T09:34:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 09:34:23 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:23 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:23 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:23 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:23 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:24 volumio2 sudo[15808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 09:34:24 volumio2 sudo[15808]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 09:34:24 volumio2 sudo[15808]: pam_unix(sudo:session): session closed for user root Jul 05 09:34:24 volumio2 sudo[15811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 09:34:24 volumio2 sudo[15811]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 09:34:24 volumio2 sudo[15811]: pam_unix(sudo:session): session closed for user root Jul 05 09:34:24 volumio2 volumio[1040]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 09:34:24 volumio2 sudo[15814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 09:34:24 volumio2 sudo[15814]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 09:34:24 volumio2 sudo[15814]: pam_unix(sudo:session): session closed for user root Jul 05 09:34:24 volumio2 sudo[15817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 09:34:24 volumio2 sudo[15817]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 09:34:24 volumio2 sudo[15817]: pam_unix(sudo:session): session closed for user root Jul 05 09:34:24 volumio2 volumio[1040]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 05 09:34:24 volumio2 volumio[1040]: info: Listing playlists Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 09:34:24 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetQueue Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreStateMachine::getQueue Jul 05 09:34:26 volumio2 volumio[1040]: info: CorePlayQueue::getQueue Jul 05 09:34:26 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:26 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10755. Jul 05 09:34:26 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:26 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:26 volumio2 go-librespot[15834]: Librespot-go daemon starting... Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=info msg="generated new device id: 58e05885e5f0e05e15f8c15abc7a7a6ff9633789" Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:26 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:26 volumio2 volumio[1040]: info: Connection to go-librespot Websocket established Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=debug msg="new websocket client" Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=debug msg="obtained new client token: AAA9tTH+nPGU7rfJRG0JF3LfG3Q0P5lYYu2cg0+b4HsttkojX0grhyzsaJCB2k/f+LtX+6SWHcgNy2m3D4doXbHwqIcYjp426HnNCbB4zS+0qsUW9znu8cFVa6OU3widaia/V0+9Iy6SuX7A5nMGsYWavewRSDiPR1XOllJEEP0yvItOR79Chgqt+/QFHE61KoydaLioDKiXHyKjMiHQq7devQAFmIqYPTGZHeviVD44htibU6apwLw+zXgA" Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 09:34:26 volumio2 volumio[1040]: info: Discovery: Getting this device information Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:26 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:26 volumio2 go-librespot[15834]: time="2025-07-05T09:34:26+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:27 volumio2 go-librespot[15834]: time="2025-07-05T09:34:27+07:00" level=debug msg="completed challenge" Jul 05 09:34:27 volumio2 go-librespot[15834]: time="2025-07-05T09:34:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:27 volumio2 volumio[1040]: info: Connection to go-librespot Websocket closed Jul 05 09:34:27 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:27 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 05 09:34:28 volumio2 volumio[1040]: info: Received Get System Info Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 09:34:28 volumio2 volumio[1040]: info: Discovery: Getting this device information Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:28 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 09:34:29 volumio2 volumio[1040]: info: Getting Spotify volume Jul 05 09:34:29 volumio2 volumio[1040]: (node:1040) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:29 volumio2 volumio[1040]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 09:34:29 volumio2 volumio[1040]: (node:1040) 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: 1395) Jul 05 09:34:29 volumio2 volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 05 09:34:29 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetState Jul 05 09:34:29 volumio2 volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 05 09:34:30 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:30 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:30 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:30 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10756. Jul 05 09:34:30 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:30 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:30 volumio2 go-librespot[15845]: Librespot-go daemon starting... Jul 05 09:34:30 volumio2 go-librespot[15845]: time="2025-07-05T09:34:30+07:00" level=info msg="generated new device id: ae84bbbc2556aacbe15aa92a8eaf47c87c99ca38" Jul 05 09:34:30 volumio2 go-librespot[15845]: time="2025-07-05T09:34:30+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:30 volumio2 go-librespot[15845]: time="2025-07-05T09:34:30+07:00" level=debug msg="obtained new client token: AABvTTKdlyHVnJP5kvjk8HVmEpXVW/3HOIfx55mJ4cZ38JeNMPj3MbKlaMp6S/BCPBX8IPWxGkuQWfOXmoxzk1st+Mba6lm5zqbBjSIVP9Z/EV5QH+jAaoPy9uc7SDL3bZFd0UAmww/dECGnNbQMOD7NK3ib2i8aa8qXe5Huuko3z1+6GeoxrI4KeFyj0ujR9zxEHXHU26sec2SQwfUThcECTThsyWcEA0HSg4EKx/VvEVtzPKet3YKL72c6" Jul 05 09:34:30 volumio2 go-librespot[15845]: time="2025-07-05T09:34:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:30 volumio2 go-librespot[15845]: time="2025-07-05T09:34:30+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:31 volumio2 go-librespot[15845]: time="2025-07-05T09:34:31+07:00" level=debug msg="completed challenge" Jul 05 09:34:31 volumio2 go-librespot[15845]: time="2025-07-05T09:34:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:31 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:31 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: info: Retrieving Cloud Streaming UI Jul 05 09:34:31 volumio2 volumio[1040]: info: Getting Tidal Cloud Configuration Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: info: Getting Qobuz Cloud Configuration Jul 05 09:34:31 volumio2 volumio[1040]: info: Asking plugin for UI Config Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: info: Getting Spotify Cloud Configuration Jul 05 09:34:31 volumio2 volumio[1040]: info: Asking plugin for UI Config Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: info: Saving Spotify Acccount Jul 05 09:34:31 volumio2 volumio[1040]: info: Got Tidal Cloud Configuration Jul 05 09:34:31 volumio2 volumio[1040]: info: Got it Jul 05 09:34:31 volumio2 volumio[1040]: info: Got it Jul 05 09:34:31 volumio2 volumio[1040]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 09:34:31 volumio2 volumio[1040]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 09:34:31 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 05 09:34:33 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:33 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:33 volumio2 volumio[1040]: info: Disabling MyMusic plugin upnp Jul 05 09:34:33 volumio2 sudo[15855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jul 05 09:34:33 volumio2 sudo[15855]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 09:34:33 volumio2 systemd[1]: Stopping UPnP Renderer front-end to MPD... Jul 05 09:34:33 volumio2 volumio[1040]: error: Upnp client error: Error: This socket has been ended by the other party Jul 05 09:34:34 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:34 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10757. Jul 05 09:34:34 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:34 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:34 volumio2 go-librespot[15857]: Librespot-go daemon starting... Jul 05 09:34:34 volumio2 go-librespot[15857]: time="2025-07-05T09:34:34+07:00" level=info msg="generated new device id: 6c7706690e388aac919d87563f37b781fd8772fb" Jul 05 09:34:34 volumio2 go-librespot[15857]: time="2025-07-05T09:34:34+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:34 volumio2 go-librespot[15857]: time="2025-07-05T09:34:34+07:00" level=debug msg="obtained new client token: AADH8wQjVMMavIFbgiNScNaSNSC6EdijejWvsJCllWU+M31ZuU4/8MlZZEXrMTGk2xSymHYEiTbj3sFPftTrgpzqsasbA8Mh2mBVr5ayCpePrLaNqSRxSN87cRtzQhmiNXUIlI3Un87rnd/ZW3u8RaeEoMNOhtdzqfwBReqO5FMi7AXWm/0K3oKEDvIEJ8T9G4tmS/7OOwVOz/v5BzejU8QjpVzbMmh5Ipr2imNxwwIKoV5QPtjsaRzQDl29" Jul 05 09:34:34 volumio2 go-librespot[15857]: time="2025-07-05T09:34:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:34 volumio2 go-librespot[15857]: time="2025-07-05T09:34:34+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:35 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 09:34:35 volumio2 go-librespot[15857]: time="2025-07-05T09:34:35+07:00" level=debug msg="completed challenge" Jul 05 09:34:35 volumio2 go-librespot[15857]: time="2025-07-05T09:34:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:35 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:35 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:36 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:36 volumio2 volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 09:34:38 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 09:34:38 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10758. Jul 05 09:34:38 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 05 09:34:38 volumio2 systemd[1]: Started go-librespot Daemon. Jul 05 09:34:38 volumio2 go-librespot[15881]: Librespot-go daemon starting... Jul 05 09:34:38 volumio2 go-librespot[15881]: time="2025-07-05T09:34:38+07:00" level=info msg="generated new device id: d05937816164bbf775694d2adb25401808d0c336" Jul 05 09:34:38 volumio2 go-librespot[15881]: time="2025-07-05T09:34:38+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 05 09:34:38 volumio2 go-librespot[15881]: time="2025-07-05T09:34:38+07:00" level=debug msg="obtained new client token: AACS346eymDspfL+WtefI8FN/4HIrtsg+KYRzPKA0VMbe4E/SzK4aKrAVPkmJtBstNu1svxwbKAZl9JXKNO04ZBWZH58ckMYht2CsDhemvR/+/7ygpZ8nNjdPVrC9RbtxIFbZfCjDMghqbfXJxAbKqt9Rs1Nyejm2GAUGzstD8jaOD1reH+g8J3cNRmL4Qdr8fglkvtvHjil7tHrQmSNyLDJ7OouDv6rqi4xVr7UYkH+bBIonXdwZMcTrl6T" Jul 05 09:34:38 volumio2 go-librespot[15881]: time="2025-07-05T09:34:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 09:34:38 volumio2 go-librespot[15881]: time="2025-07-05T09:34:38+07:00" level=debug msg="completed keyexchange" Jul 05 09:34:39 volumio2 volumio[1040]: info: Initializing connection to go-librespot Websocket Jul 05 09:34:39 volumio2 go-librespot[15881]: time="2025-07-05T09:34:39+07:00" level=debug msg="new websocket client" Jul 05 09:34:39 volumio2 volumio[1040]: info: Connection to go-librespot Websocket established Jul 05 09:34:39 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 09:34:39 volumio2 go-librespot[15881]: time="2025-07-05T09:34:39+07:00" level=debug msg="completed challenge" Jul 05 09:34:39 volumio2 go-librespot[15881]: time="2025-07-05T09:34:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 09:34:39 volumio2 volumio[1040]: info: Connection to go-librespot Websocket closed Jul 05 09:34:39 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 09:34:39 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 09:34:39 volumio2 volumio[1040]: info: Enabling MyMusic plugin upnp Jul 05 09:34:39 volumio2 volumio[1040]: info: Enabling plugin upnp Jul 05 09:34:39 volumio2 volumio[1040]: info: Loading plugin "upnp"... Jul 05 09:34:39 volumio2 volumio[1040]: info: [1751682879913] Starting Upmpd Daemon Jul 05 09:34:39 volumio2 volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 05 09:34:39 volumio2 volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 09:34:39 volumio2 volumio[1040]: Error: listen EADDRINUSE: address already in use :::6599 Jul 05 09:34:39 volumio2 volumio[1040]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jul 05 09:34:39 volumio2 volumio[1040]: at listenInCluster (net.js:1379:12) Jul 05 09:34:39 volumio2 volumio[1040]: at Server.listen (net.js:1465:7) Jul 05 09:34:39 volumio2 volumio[1040]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jul 05 09:34:39 volumio2 volumio[1040]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jul 05 09:34:39 volumio2 volumio[1040]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jul 05 09:34:39 volumio2 volumio[1040]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 05 09:34:39 volumio2 volumio[1040]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jul 05 09:34:39 volumio2 volumio[1040]: code: 'EADDRINUSE', Jul 05 09:34:39 volumio2 volumio[1040]: errno: -98, Jul 05 09:34:39 volumio2 volumio[1040]: syscall: 'listen', Jul 05 09:34:39 volumio2 volumio[1040]: address: '::', Jul 05 09:34:39 volumio2 volumio[1040]: port: 6599 Jul 05 09:34:39 volumio2 volumio[1040]: } Jul 05 09:34:39 volumio2 volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 09:34:40 volumio2 sudo[15900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-05 09:33 Jul 05 09:34:40 volumio2 sudo[15900]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 05:26:48 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a63f40325536655a08b14de2b295ce76"