-- Logs begin at Mon 2025-09-15 20:20:27 +07, end at Mon 2025-09-15 22:32:57 +07. -- Sep 15 22:31:00 volumio go-librespot[8052]: time="2025-09-15T22:31:00+07:00" level=debug msg="obtained new client token: AADGQNyNSbHbnvZxVSEDQBZngW1MWrztMtHORQ93v/vY5N39TPPYQ4+COC7cWcLM/bVxTFLv0xMJraP6inX2VpaEWWz2QkKSSdgFEzt6WV0r11BukQSy9LiQ5B+eGuQQytMWVeECvx3NbLQdXi1COtC5dwzigbKDdl5EMrPFy5Ymo9fBTnX0HIUAlUtob0AVrV9TqoKd4qM37EozlJRcmdWdB7yjiqSvgoW/gq6wDzXGNMo2Pc3Y/NC/" Sep 15 22:31:00 volumio go-librespot[8052]: time="2025-09-15T22:31:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:00 volumio go-librespot[8052]: time="2025-09-15T22:31:00+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:00 volumio go-librespot[8052]: time="2025-09-15T22:31:00+07:00" level=debug msg="completed challenge" Sep 15 22:31:00 volumio go-librespot[8052]: time="2025-09-15T22:31:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:01 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:01 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522373. Sep 15 22:31:03 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:03 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:03 volumio go-librespot[8063]: go-librespot daemon starting... Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="app state loaded" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=info msg="zeroconf server listening on port 45953" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="obtained new client token: AABGVqUT5+zocqIXcMBXIhr099WlVQPajyfgL3dD2oRnxEG8fqekYlk9IPGew3pnC5EJbE4p2t6OCAI85aPN90swlMQyUIOy0zTeeFf8QM71ebqkqeaNrRyK3XYG5TDLq2UqSL66Syjw7fkgn6JVQTtnki7JNIls0ZvwDAwKw85FCWYUqWC6UwOoIMhWpC1g8uN+sOwbYpTG3Qi9FrFe2moSLymNQ6RuGpy5vh9ll3hYzMqcOM41eGnBb3I=" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=debug msg="completed challenge" Sep 15 22:31:03 volumio go-librespot[8063]: time="2025-09-15T22:31:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:04 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:04 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522374. Sep 15 22:31:07 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:07 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:07 volumio go-librespot[8084]: go-librespot daemon starting... Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="app state loaded" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=info msg="zeroconf server listening on port 38471" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="obtained new client token: AABwCr8Lh9PcA3s4vYAR/7jWNZl8jyHqKGmFHyw9qsJ7TFKeSGbtme2pzxoz/6e//91UjdpT2X3HFRGW0v3jBuuGd3lV0Dcb36ooaQvIMvv7eC8IRD7rvzzbZuiv+NaJypxj4V4xbRV3kpoX3NmRYscpyi6sd4qDwDFHtuISpnNh6QsVMdHKbeZzvVwVa/Ej60SH9/QPocxJLfQBFJ/PGGix5Bszu6ovl1C687eNoRqWoo+QRtU2VWDOeLQ=" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=debug msg="completed challenge" Sep 15 22:31:07 volumio go-librespot[8084]: time="2025-09-15T22:31:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:07 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:07 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522375. Sep 15 22:31:10 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:10 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:10 volumio go-librespot[8092]: go-librespot daemon starting... Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="app state loaded" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31: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]" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=info msg="zeroconf server listening on port 44847" Sep 15 22:31:10 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:10 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="new websocket client" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="obtained new client token: AACMvDILPCbNzRjcDx2NNxD3t5CK5sOQUsNXcuaDJQyGZlFNy2Ppp+THZHCCzecw4hcO7omn2i9gqNh/8orKyHeOgWWspoxwIIUuMr5lgoN8ObHVt554u9RcR4xM1xP09orO/dzBLuid5dY+GwTh8NEeJvtLLQo84msSFTQpEg7EZ1SxTI1pK0rgafkIJLICqUcfgXD00BBnbtLg63N8uk+k0inLCBeEhYfJ+3FwRG2p2vJa837kKR8WY5o=" Sep 15 22:31:10 volumio go-librespot[8092]: time="2025-09-15T22:31:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:11 volumio go-librespot[8092]: time="2025-09-15T22:31:11+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:11 volumio go-librespot[8092]: time="2025-09-15T22:31:11+07:00" level=debug msg="completed challenge" Sep 15 22:31:11 volumio go-librespot[8092]: time="2025-09-15T22:31:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:11 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:31:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:13 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:31:13 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:13 volumio volumio[1076]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 15 22:31:13 volumio volumio[1076]: (node:1076) 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: 93199) Sep 15 22:31:13 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 22:31:13 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:31:13 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:31:14 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:14 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522376. Sep 15 22:31:14 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:14 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:14 volumio go-librespot[8143]: go-librespot daemon starting... Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="app state loaded" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=info msg="zeroconf server listening on port 36481" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="obtained new client token: AABz/19EQxY52Z1/ZhWAt45Z94vkL0cLitQ9DlmvRQXm9JmElKf6EyV56KjII8ej12NXaBZhrP0Qt0LHcLdr10efaKLxfbIjdSxJuJC2dr4VFLRVO1NqyafESUfZTldWxYV5BFZ+miY4/WW96rFrhKCJgbLMgCMEX6DPSYjgMJGy8NYDxOmeVXWG2pb+nKe4wBDtUwJnd8yVdLMqGs8hB6yLT7+xLezSA+KdRQ8vnWdBi+e5qzT6ddOI5Qc=" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=debug msg="completed challenge" Sep 15 22:31:14 volumio go-librespot[8143]: time="2025-09-15T22:31:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:17 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:17 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522377. Sep 15 22:31:17 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:17 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:17 volumio go-librespot[8165]: go-librespot daemon starting... Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=debug msg="app state loaded" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+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]" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:17 volumio go-librespot[8165]: time="2025-09-15T22:31:17+07:00" level=info msg="zeroconf server listening on port 35397" Sep 15 22:31:18 volumio go-librespot[8165]: time="2025-09-15T22:31:18+07:00" level=debug msg="obtained new client token: AACpoPN+yD+QZT2jvCFO5Gsdumg3fywgTIFefqWXvH/6836WOZeFIb4Q+LWLZ9nVugDXVcDoKLS8QQLVJvL4vMF0yrLdSeVJJ2b4HkYjyZeD6SpUi/HyG72YdQu5FmUexNouEykeL/PfEugol+Cr2f1okEb5JOdFaGT04h6DJFWQi7xYMddZyGxhprdy+LKWse/49HqLKaeTX8n4ysM0HD+CNXPx85S1INbA3ZT8R9WOgNRqxh1/KS5Y" Sep 15 22:31:18 volumio go-librespot[8165]: time="2025-09-15T22:31:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:18 volumio go-librespot[8165]: time="2025-09-15T22:31:18+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:18 volumio go-librespot[8165]: time="2025-09-15T22:31:18+07:00" level=debug msg="completed challenge" Sep 15 22:31:18 volumio go-librespot[8165]: time="2025-09-15T22:31:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:20 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:20 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522378. Sep 15 22:31:21 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:21 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:21 volumio go-librespot[8173]: go-librespot daemon starting... Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=debug msg="app state loaded" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+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]" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=info msg="zeroconf server listening on port 43813" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=debug msg="obtained new client token: AADbNGYEbIdqPVxA8P3AKZC6hJniR9okwhvDshY3tpYLYJHjnnWKvifHRgAdh2eOr4Yf9KPD2mSOM3xl4frVzlaCStMTxIsOf1jiLQCmbx5TKKRTI9fhtt7Lr4M0nwkfp406lDefXNnYdKl99A1AbtjLaceLp4n5zzi6DmgPM4bq21cym64AVdFB+2Qxv+pBceL8EwMWWJC99G5iVNpnzvscP450o3+IhZj8m+9VsqQYlXJ4H6Z1mRUO5uo=" Sep 15 22:31:21 volumio go-librespot[8173]: time="2025-09-15T22:31:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 15 22:31:22 volumio go-librespot[8173]: time="2025-09-15T22:31:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Sep 15 22:31:22 volumio go-librespot[8173]: time="2025-09-15T22:31:22+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:22 volumio go-librespot[8173]: time="2025-09-15T22:31:22+07:00" level=debug msg="completed challenge" Sep 15 22:31:22 volumio go-librespot[8173]: time="2025-09-15T22:31:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:23 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:23 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522379. Sep 15 22:31:25 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:25 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:25 volumio go-librespot[8183]: go-librespot daemon starting... Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="app state loaded" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+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]" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=info msg="zeroconf server listening on port 42443" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="obtained new client token: AADo/IP5qJ8X8Ys/NAez5OUVzuaM+MO/4hrtu6EWlDW8It98D9ZAw/dAXzjzeOUE99AYiwwFOXo4ZJWyMIDVuoPJbQ33QJiHmfobxeifaX85n6XkMGnXBlev2zRkDP0Un57V89zEUUjQ3VBfrelAOjNBt927kmIFV6rI7lTqKfhmrVxfyJOFb5rKTsdmPuUXtI4Hx7qPyxnMXKCnua/c2+R0hiL6QAb7TmsSdUIsy3nItrsJCp89+z11MxA=" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=debug msg="completed challenge" Sep 15 22:31:25 volumio go-librespot[8183]: time="2025-09-15T22:31:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:26 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:26 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522380. Sep 15 22:31:28 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:28 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:28 volumio go-librespot[8205]: go-librespot daemon starting... Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=debug msg="app state loaded" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+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]" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:28 volumio go-librespot[8205]: time="2025-09-15T22:31:28+07:00" level=info msg="zeroconf server listening on port 38325" Sep 15 22:31:29 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=debug msg="new websocket client" Sep 15 22:31:29 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=debug msg="obtained new client token: AAAI0ih7lniog6QeUixCLBTB4clrAGC5AQWDGxIhKkuQxV1zbZGEDPObYwec5EDeKSGQRlHrjasn3g1Grdvh7rTG9XNzNlf5r6BgsGYV/OwsBPHidzq01DsqEh4bhJMdRasdZayPlZd4VrvuDKxGJMzxbssQmsSgoc+ItUjpW+v3SfB+xD0GfQZWycq35QrmSNaJEqVN6sWiRj0WdrWb2auyB1qEqZzer8+4vo/PQ5nxBX31JvwtaSAd" Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=debug msg="completed challenge" Sep 15 22:31:29 volumio go-librespot[8205]: time="2025-09-15T22:31:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:29 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:31:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:32 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:31:32 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:32 volumio volumio[1076]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 15 22:31:32 volumio volumio[1076]: (node:1076) 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: 93200) Sep 15 22:31:32 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 22:31:32 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:31:32 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:31:32 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:32 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522381. Sep 15 22:31:32 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:32 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:32 volumio go-librespot[8212]: go-librespot daemon starting... Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="app state loaded" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+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]" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=info msg="zeroconf server listening on port 43831" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="obtained new client token: AABLaYuOZNN7IvBhNDYuVOdXNbLcnJcRpiOVrX3ZwWePzyiPvBDnF7GQn83M5KbXKhmF01Lp1wMRoTdZ85VeYI6s+3VoGdSxEXhHbwJXt4a9+/WFrhEiFuTZK3axzHHbZ4URh5nQTOdz9er40ZCVjZTg4eo2T1ovhzRcQQ+l1hxbOhYseOYnxMdL7ApsrYn4wgcFI/74r/sY0JAWm6YvD1pbVDz8dVLOuMfV69Z5NEw+MeFuiCW6NZNKSBc=" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:32 volumio go-librespot[8212]: time="2025-09-15T22:31:32+07:00" level=debug msg="completed challenge" Sep 15 22:31:33 volumio go-librespot[8212]: time="2025-09-15T22:31:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:35 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:35 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522382. Sep 15 22:31:36 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:36 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:36 volumio go-librespot[8222]: go-librespot daemon starting... Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="app state loaded" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+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]" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=info msg="zeroconf server listening on port 38433" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="obtained new client token: AADd0VTbXN9Im8CBWQE6E8RWbQ176FR+IVku/+Ck8muIjk89+OF7KwIjbpNFQF5ya6zSNZW1XxypQZA1v04w7mO0z2SljKQKm9piE70CQqApuJzSxt48527YoI75xuU+RyJVD5W+0ZKj3+YpbnAzcvj54LrOFn70JoONtlVNmst1DpX66g8nVZ6chE6/rFG7C1vDUlCEovfk7VOmzyJ5/jzX84RYfGHvBu5OesTUILA/mTLol0/InvK9FKU=" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=debug msg="completed challenge" Sep 15 22:31:36 volumio go-librespot[8222]: time="2025-09-15T22:31:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:38 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:38 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522383. Sep 15 22:31:39 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:39 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:39 volumio go-librespot[8243]: go-librespot daemon starting... Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=debug msg="app state loaded" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+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]" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:39 volumio go-librespot[8243]: time="2025-09-15T22:31:39+07:00" level=info msg="zeroconf server listening on port 34923" Sep 15 22:31:41 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:41 volumio go-librespot[8243]: time="2025-09-15T22:31:41+07:00" level=debug msg="new websocket client" Sep 15 22:31:41 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:31:44 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:31:44 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 22:31:44 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:31:44 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:31:45 volumio go-librespot[8243]: time="2025-09-15T22:31:45+07:00" level=debug msg="obtained new client token: AAD5ZCIYTfvjUX0U1+p0Bu9VXKtCk286wrXKDnlGxuuO8pXorsmNKeEzyYgQ6PE1KRut5eGvEBb3VrC39xCsdWaICbX8nv1X4bozx9xZsapJgQteQsIsYI8msZgRzVvDX7XveOLOL7W6HhfKYvVMDICYUe7JH2qH80JG8S+mKyPS9SC68b/kupwJMCgJ92+FHrIJtrm2VLhEB2MJGXL4Sc6GjZJAs9sISYL7ehdftAS7arLVvjHstroS" Sep 15 22:31:45 volumio go-librespot[8243]: time="2025-09-15T22:31:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:45 volumio go-librespot[8243]: time="2025-09-15T22:31:45+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:45 volumio go-librespot[8243]: time="2025-09-15T22:31:45+07:00" level=debug msg="completed challenge" Sep 15 22:31:45 volumio go-librespot[8243]: time="2025-09-15T22:31:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:45 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: socket hang up Sep 15 22:31:45 volumio volumio[1076]: at connResetException (internal/errors.js:639:14) Sep 15 22:31:45 volumio volumio[1076]: at Socket.socketOnEnd (_http_client.js:499:23) Sep 15 22:31:45 volumio volumio[1076]: at Socket.emit (events.js:412:35) Sep 15 22:31:45 volumio volumio[1076]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 15 22:31:45 volumio volumio[1076]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 15 22:31:45 volumio volumio[1076]: (node:1076) 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: 93201) Sep 15 22:31:45 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:48 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:48 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522384. Sep 15 22:31:48 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:48 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:48 volumio go-librespot[8267]: go-librespot daemon starting... Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="app state loaded" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+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]" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=info msg="zeroconf server listening on port 39499" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="obtained new client token: AACa361OreZ00DiYgQWSjI7StZRQIZpjuhFsG6bHnbiypl7BNfMA9f0LujJTiqkKQG5c3eBaaN0ebLldbu+r9nxR4fsffNbodTIAdBUZ7A/O3X9Pl7ORfJCPUQ5mdqy1f6gIIBbQhiFwRuSUhqnuxm1NfTWKqYv4f2TBGy6W+5VCYK6v0f7e1LlmXTHCkpSy96pk5X/jBl2GGZtmVq7jpEOa+UKGeli/e40ljsTzKiR9/pHzckfzqkYPVro=" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:48 volumio go-librespot[8267]: time="2025-09-15T22:31:48+07:00" level=debug msg="completed challenge" Sep 15 22:31:49 volumio go-librespot[8267]: time="2025-09-15T22:31:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:51 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:51 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522385. Sep 15 22:31:52 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:52 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:52 volumio go-librespot[8274]: go-librespot daemon starting... Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="app state loaded" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+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]" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=info msg="zeroconf server listening on port 45541" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="obtained new client token: AACa+ebUTE5LX7d72ZpIWlN9kQbjRCCf+GgMlQCDfHXjY+S2pyAVqn3lphwAtjqHTo3jOYvDPm4mUoy4Gd1GclITgzbCm/BJR8+onJGpKfSYOgYZeE5kMWjQR3DpMXTiMalH8pFXwXOIEE7koPSIegeOr+470CADs0MFFANm6idH9fmHsGEwZ6EdrvGDEnZ0GHd4bL6nC5gBYF2+Myz0KYF/jBbD9ZYIkT4GTxAaMfbjuyiugzY0N++Abxk=" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=debug msg="completed challenge" Sep 15 22:31:52 volumio go-librespot[8274]: time="2025-09-15T22:31:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:54 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:54 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522386. Sep 15 22:31:55 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:55 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:55 volumio go-librespot[8281]: go-librespot daemon starting... Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=debug msg="app state loaded" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+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]" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=info msg="zeroconf server listening on port 36197" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=debug msg="obtained new client token: AABwvrYNjKnGs3iGRi6F7ohGq+JO3IGYEKMKYBidlOgqo2kCXugYV1b0/D+rRMIRyjFnvBhn3sbK2qYH4HBb56Xx8aE+xjot+TA6reXRxxD8Glz0exc5zdl5tuK5U1mLo2XWRnFY+LdEjrtn++QCshaQQ9UXgIVtORYjfdQUqtkSN0HK4tDgxYUwfTHSmS9nR064n5GVUz2pFPUGkAxOYbcsiPTvw7G0BmAZnOS2jJEaLruKgZbVzqnuOUs=" Sep 15 22:31:55 volumio go-librespot[8281]: time="2025-09-15T22:31:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:56 volumio go-librespot[8281]: time="2025-09-15T22:31:56+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:56 volumio go-librespot[8281]: time="2025-09-15T22:31:56+07:00" level=debug msg="completed challenge" Sep 15 22:31:56 volumio go-librespot[8281]: time="2025-09-15T22:31:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:31:57 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:31:57 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:31:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:31:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522387. Sep 15 22:31:59 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:31:59 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:31:59 volumio go-librespot[8302]: go-librespot daemon starting... Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="app state loaded" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+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]" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=info msg="zeroconf server listening on port 46451" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="obtained new client token: AAC+7isqeeA3mQQGAW1rhtcbAoNgAN22TJwDsYmKodSNwMhyY7jnkzreLfSV/7s2ZGHdgnsDZwN8F+wSrM2DfnGRBUalrpNs5e3RGGGXWyXaODT0fMzBxoJQFYX0d2Auu4twZuvfqxvmoYFDltcC9HI8j7JUePqG1mPJ3+RIS/FziOMlREavDyV980LHkemf/N13c2Y4dRDOa+Bh71MUIdOdE80EgyJg7zespDWddEfjYFEEnXrwDdU3oPA=" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="completed keyexchange" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=debug msg="completed challenge" Sep 15 22:31:59 volumio go-librespot[8302]: time="2025-09-15T22:31:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:31:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:31:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:00 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:00 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522388. Sep 15 22:32:03 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:03 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:03 volumio go-librespot[8314]: go-librespot daemon starting... Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="app state loaded" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=info msg="zeroconf server listening on port 43483" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="obtained new client token: AAD9KdEMfye+64CefQtAS9iE7BM83cmEgIHKPBMvVHyfaQwkt+S5kPg8wHVaTJ/73l5/RpyyClnmJ9XdJVqtS/hPhWoPWACnzTfPxRNBewDgwVbfwdtQfCPEDhuMmF55nzkrfnFbuYJwxqAuF9OHHLc/9IaErPGjmJu/a9WgbauCMykRWPg/qwh78TBH5ztuT+EpoZsQdN9lL8Av1y2xzqeHKw8Ot5FteUeY15m/4FBEoXFGyM9yJm1fLVk=" Sep 15 22:32:03 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="new websocket client" Sep 15 22:32:03 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=debug msg="completed challenge" Sep 15 22:32:03 volumio go-librespot[8314]: time="2025-09-15T22:32:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:03 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:32:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:06 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:32:06 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:06 volumio volumio[1076]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 15 22:32:06 volumio volumio[1076]: (node:1076) 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: 93202) Sep 15 22:32:06 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 22:32:06 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:06 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:32:06 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:06 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522389. Sep 15 22:32:06 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:06 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:06 volumio go-librespot[8322]: go-librespot daemon starting... Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="app state loaded" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=info msg="zeroconf server listening on port 32845" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="obtained new client token: AACZJDGlzMOurcs/f+mViMNjWtpOH0kjGm5gWZBYNNkjQyK41CcWIAnyEcix9iuCQgkjmDLbbba0NkZahQ/aRBRWaRTZSlKepZ7yZXnPAsiwLvrOsq+r+5qg8CDJbpt/KybStk5vJEOvNPtz4FOC0ilqVzSm1UtEIrM1b1U1VlFLy9CeYZP0zwAyTVVH+8IZ6kVF9WGButdcgqdLCOz7Jn4atSZG8KekuTEr0q/FxSirG/3f1+xUgDaDrKE=" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=debug msg="completed challenge" Sep 15 22:32:06 volumio go-librespot[8322]: time="2025-09-15T22:32:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:09 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:09 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522390. Sep 15 22:32:10 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:10 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:10 volumio go-librespot[8351]: go-librespot daemon starting... Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="app state loaded" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=info msg="zeroconf server listening on port 32991" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="obtained new client token: AABaqUqZa5UsnocIZkg4goDp1ONsaZCLHilP9/c7gevALkBatxZ07wZfYvxkc0eM3gDQoL1TwFclrXKBODYy1U4rT0J+us8ctSHWx0dIMYJxO+xZyRadrTyu4CuMQihiknVaDwM6ugeTvViGnjM+SKhpj7+wzzjorNffXQ23hjRs1OOp9bY8ofHyCNQ9MmHekKCXw9d4GFUlJZx/eAAHsKx6XyxXv9Ptw1oMk/sfwk+r1y65vlc1DhCghdE=" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=debug msg="completed challenge" Sep 15 22:32:10 volumio go-librespot[8351]: time="2025-09-15T22:32:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:12 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:12 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522391. Sep 15 22:32:13 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:13 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:13 volumio go-librespot[8401]: go-librespot daemon starting... Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="app state loaded" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+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]" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=info msg="zeroconf server listening on port 42981" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="obtained new client token: AABtzPhwJo4Dzj2fsYGThWc6hqEg2fAhg5yHFgUFrcSt4SbjhcrPrEaiFWmli2MiTtFXy3neYWD6S82VY1shn2g5pVd9XIt9TtMHW/obfP+mlp509TFxchTscmm6G0M5GFYxSQfmcou5wabgxgfdEdRqF1LxSuUepCuLc9LJ+Ap79P9acmKRljfjdVF1vfae7wAUFwp/2jdhbVPtsRyU+N+mxVn/Kuiyxudc6FEna70Y/hgM3taWg5ZVmUo=" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:13 volumio go-librespot[8401]: time="2025-09-15T22:32:13+07:00" level=debug msg="completed challenge" Sep 15 22:32:14 volumio go-librespot[8401]: time="2025-09-15T22:32:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:15 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:15 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522392. Sep 15 22:32:17 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:17 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:17 volumio go-librespot[8423]: go-librespot daemon starting... Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="app state loaded" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+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]" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=info msg="zeroconf server listening on port 33971" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="obtained new client token: AADfKy0/U2s5Rp5UzOe/3yheK8Ck2Yny3RZc104AKuNBNHK35dMBNRDdL4k9SFry2LsqKpFQBQgzGptfIJ1PtJE99a/51VtQDZVhiHFLX/iFfyDA0/z5UYxAIQR2wP0E0CIoQPIVS52oQTyQ6W58PTt1ZIuNC8njMkILqd1exrWJk4ddalCU1TCjWZMJH4OSahAFwd4+Ch3Lh9Z/pjggMI3rpQ26ftTSgv5WrGj/8zIzpZcQXyQpRTXyOME=" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=debug msg="completed challenge" Sep 15 22:32:17 volumio go-librespot[8423]: time="2025-09-15T22:32:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:18 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:18 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522393. Sep 15 22:32:21 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:21 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:21 volumio go-librespot[8429]: go-librespot daemon starting... Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="app state loaded" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+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]" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=info msg="zeroconf server listening on port 34719" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="obtained new client token: AABY2cUiYKUpBprSxqHkADU73SH0E0ATA2iVy67QuOBrV/cKLD/6kQ/vLOT4fokff5YXT2Yr4idjMgYNJSSr5ylOiElBZV0mLVzdkdjZ+svNBucJ6ILaPxoLxH5oTcdeAJaI0ONKOTKMaZUZKzZz02OtP/5zmgNXMFuDg7qj4qK2Hi581of16jW5JddaAC/OhVF+ESf0713nz0gOn69Wza4Io5lZtpyplTjXbeDigD3NsAGuWHM7mxx0fyc=" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:21 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="new websocket client" Sep 15 22:32:21 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=debug msg="completed challenge" Sep 15 22:32:21 volumio go-librespot[8429]: time="2025-09-15T22:32:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:21 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:24 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:32:24 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:24 volumio volumio[1076]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 15 22:32:24 volumio volumio[1076]: (node:1076) 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: 93203) Sep 15 22:32:24 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 22:32:24 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:24 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:32:24 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:24 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522394. Sep 15 22:32:24 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:24 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:24 volumio go-librespot[8439]: go-librespot daemon starting... Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=debug msg="app state loaded" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+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]" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 15 22:32:24 volumio go-librespot[8439]: time="2025-09-15T22:32:24+07:00" level=info msg="zeroconf server listening on port 42063" Sep 15 22:32:25 volumio go-librespot[8439]: time="2025-09-15T22:32:25+07:00" level=debug msg="obtained new client token: AACX0msTcbdW43+U1VoZfz2a+Bs+X1zwtACjWEkGw+SyOI2+CSWCVHGLT8EW3u/Sd90zk97U5c2Pw6kLDgVklRaKtT7Pv5JiT2ZBkRQw4HqU98cEDs7PiyDEJGH9yarTTAIiEYQtGSKU/JwMhTP5SQOfsJ8WrvPAKtshgnFvC6t16kfGjrQUYPUZYHxH7xw1YFos3VlZrcEIZk0u7V9MCbQJqQrpBFv2E02yr4fqmfUoZWm2i2CbtT15" Sep 15 22:32:25 volumio go-librespot[8439]: time="2025-09-15T22:32:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:25 volumio go-librespot[8439]: time="2025-09-15T22:32:25+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:25 volumio go-librespot[8439]: time="2025-09-15T22:32:25+07:00" level=debug msg="completed challenge" Sep 15 22:32:25 volumio go-librespot[8439]: time="2025-09-15T22:32:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:27 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:27 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522395. Sep 15 22:32:28 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:28 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:28 volumio go-librespot[8460]: go-librespot daemon starting... Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="app state loaded" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+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]" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=info msg="zeroconf server listening on port 42539" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="obtained new client token: AADMo7eoMcsGxl5gIdroFB8vqevKMgdZyYtOpHEz1d+/v9ZwJsDWwh5PxvbQKbH7x4Y/qXddVciZmNyRaNDSUXL+4SNaFKLkgzowCiPYjnp19CITIlgDimRMT/gaXAc+GYotFGLbjbS5OBRlx23Xze+myfikeDbb9veyy2fhEeXOCrESAuEJGkQQqHvjdkZm5xy7jLoHH9bHIajbOHFkMmYp/3Y1nZT+V124VT1BzSe9x96+OOwu9A7TdiU=" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=debug msg="completed challenge" Sep 15 22:32:28 volumio go-librespot[8460]: time="2025-09-15T22:32:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:30 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:30 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522396. Sep 15 22:32:32 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:32 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:32 volumio go-librespot[8468]: go-librespot daemon starting... Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="app state loaded" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+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]" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=info msg="zeroconf server listening on port 34273" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="obtained new client token: AADZEPy/DFrkfVMO4BRD602O2RDgX4nl2BjyJa3ev9cCJAnhNMnCOGFxel1BiQQV/ab9Mz8dF1ZG/uu3jVkfNQj1ffbxrkjF6eSdTqF7gPyb4+1sMUBx6BKPZ980erS38VjcLRFkB/oBF+SoL6X+nXSKSBl2h9OSNCePaAp4bgq9y06UGXkUgQxzkYLLR2iU3SOmOJV4U/ii4p81+EhSLRiIv5EOieMFxHNxPB+o73qgx9cJe7vDLAxYd5Q=" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=debug msg="completed challenge" Sep 15 22:32:32 volumio go-librespot[8468]: time="2025-09-15T22:32:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:33 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:33 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522397. Sep 15 22:32:35 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:35 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:35 volumio go-librespot[8476]: go-librespot daemon starting... Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="app state loaded" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+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]" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=info msg="zeroconf server listening on port 45463" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="obtained new client token: AAASQSia7gpjifJwB0qlRQi1KtXy4palVGrEUWaT7fqCuMcsJCOYrlJs6NxI/Xs+vR5lmbYQGMHWoeZ2l0nXXzCcKERSvdNgt5wwsyHlc6eNjzS8c7M9VsKPh8DfVvQ3+9SjVdHoiVLILPTnfZUKEs2qrb8z+8tGjRDlQEbOnC9YvveaOmzTVzWcboHiG1JJHKpOJPMUevgGFHtYGqFfCeD6BrCcOaRjq7De/Faux7z/rw5CTFSAzj0a89M=" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:35 volumio go-librespot[8476]: time="2025-09-15T22:32:35+07:00" level=debug msg="completed challenge" Sep 15 22:32:36 volumio go-librespot[8476]: time="2025-09-15T22:32:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:36 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:36 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522398. Sep 15 22:32:39 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:39 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:39 volumio go-librespot[8497]: go-librespot daemon starting... Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="app state loaded" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+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]" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=info msg="zeroconf server listening on port 44061" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="obtained new client token: AAAR1r2x6a70O+67rmmiaw4w5i66tAhKlsmMPIloFwp2K2xcTTW/EPKrR7oNnOEUu+nw+oI4cUSaMrp0A7ru9+JIuZaoE2rpELxd4QJWS9CuSFTtYzxJg2GamKkjIvcYuah7PztbNmYsgcTpx0OUdW7QWWLl8wlBwR9EOu5+lhhh8FO3l89OPMxygPY/SebduuEFUNn/hVwlb3shVjAxViLGTSptioRgq/YZHy/iYZhw9H2DIZs6skIb0DM=" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=debug msg="completed challenge" Sep 15 22:32:39 volumio go-librespot[8497]: time="2025-09-15T22:32:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:39 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:39 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:42 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:42 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522399. Sep 15 22:32:42 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:42 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:42 volumio go-librespot[8504]: go-librespot daemon starting... Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=debug msg="app state loaded" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32: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]" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:42 volumio go-librespot[8504]: time="2025-09-15T22:32:42+07:00" level=info msg="zeroconf server listening on port 37623" Sep 15 22:32:43 volumio go-librespot[8504]: time="2025-09-15T22:32:43+07:00" level=debug msg="obtained new client token: AACSgX6UJ5kHt9mFKGMroS0EOm8Vc2lhk5wTmGBZ05ITPcMhvKO7Kf1m7yMcT68ZSmM7kfR/uxlpJQb8IVPLvavA1HXSuO1dlWRlSTSF5hQSUY69TJ9qqFZQTJIMW6Av+8WEh5U0sG+3duP5lNj+qPeMFZNPCzAUYnYS51kHqhk0YqsV6UzIfx0LnqXWVtuTrMZlb/J9+niN86uTYb78HrOjpD/xfx/4W6M0q8fgASpb/1XKCqYN+zyV" Sep 15 22:32:43 volumio go-librespot[8504]: time="2025-09-15T22:32:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:43 volumio go-librespot[8504]: time="2025-09-15T22:32:43+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:43 volumio go-librespot[8504]: time="2025-09-15T22:32:43+07:00" level=debug msg="completed challenge" Sep 15 22:32:43 volumio go-librespot[8504]: time="2025-09-15T22:32:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 22:32:45 volumio volumio[1076]: info: Discovery: Getting this device information Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 22:32:45 volumio volumio[1076]: verbose: New Socket.io Connection to 192.168.1.15:3000 from 192.168.1.225 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 15 22:32:45 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 15 22:32:45 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:45 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522400. Sep 15 22:32:46 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:46 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:46 volumio go-librespot[8515]: go-librespot daemon starting... Sep 15 22:32:46 volumio go-librespot[8515]: time="2025-09-15T22:32:46+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:46 volumio go-librespot[8515]: time="2025-09-15T22:32:46+07:00" level=debug msg="app state loaded" Sep 15 22:32:46 volumio go-librespot[8515]: time="2025-09-15T22:32:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:46 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:46 volumio sudo[8522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 15 22:32:46 volumio sudo[8522]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 22:32:46 volumio sudo[8522]: pam_unix(sudo:session): session closed for user root Sep 15 22:32:46 volumio sudo[8525]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 15 22:32:46 volumio sudo[8525]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 22:32:46 volumio sudo[8525]: pam_unix(sudo:session): session closed for user root Sep 15 22:32:46 volumio volumio[1076]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.225 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Sep 15 22:32:47 volumio sudo[8542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 15 22:32:47 volumio sudo[8542]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 22:32:47 volumio sudo[8542]: pam_unix(sudo:session): session closed for user root Sep 15 22:32:47 volumio sudo[8545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 15 22:32:47 volumio sudo[8545]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 22:32:47 volumio sudo[8545]: pam_unix(sudo:session): session closed for user root Sep 15 22:32:47 volumio volumio[1076]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.225 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 15 22:32:47 volumio volumio[1076]: info: Listing playlists Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 15 22:32:47 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 15 22:32:48 volumio volumio[1076]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 22:32:48 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 22:32:48 volumio volumio[1076]: info: CoreCommandRouter::volumioGetQueue Sep 15 22:32:48 volumio volumio[1076]: info: CoreStateMachine::getQueue Sep 15 22:32:48 volumio volumio[1076]: info: CorePlayQueue::getQueue Sep 15 22:32:48 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:48 volumio volumio[1076]: info: Connection to go-librespot Websocket established Sep 15 22:32:48 volumio go-librespot[8515]: time="2025-09-15T22:32:48+07:00" level=debug msg="new websocket client" Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 22:32:50 volumio volumio[1076]: info: Discovery: Getting this device information Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: info: Retrieving Cloud Streaming UI Sep 15 22:32:50 volumio volumio[1076]: info: Getting Tidal Cloud Configuration Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: info: Getting Qobuz Cloud Configuration Sep 15 22:32:50 volumio volumio[1076]: info: Asking plugin for UI Config Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: info: Getting Spotify Cloud Configuration Sep 15 22:32:50 volumio volumio[1076]: info: Asking plugin for UI Config Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: info: Saving Spotify Acccount Sep 15 22:32:50 volumio volumio[1076]: info: Got Tidal Cloud Configuration Sep 15 22:32:50 volumio volumio[1076]: info: Got it Sep 15 22:32:50 volumio volumio[1076]: info: Got it Sep 15 22:32:50 volumio volumio[1076]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 15 22:32:50 volumio volumio[1076]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::volumioGetBrowseSources Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::volumioGetBrowseSources Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::volumioGetBrowseSources Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 22:32:50 volumio volumio[1076]: info: Received Get System Info Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 22:32:50 volumio volumio[1076]: info: Discovery: Getting this device information Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:50 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+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]" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=info msg="zeroconf server listening on port 38113" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="obtained new client token: AADObRHlP+vf9fP9L/VNzycXBfJupE2obo8Jv7GpBUvUjcg3ItYQT4cf2rulRo7O84PF34Okql4a9DBkSonew+xpq0pSeW1ETYsRryByqx236K4fvhz34SeRF6U6WLMlWd5yffT0uSuKg+RPDxHCj4SgMRtp8vQwVOgn9E86pz88p+DR95R+whNwU9cLhofnRgcOTUG0bsVI+PbWYGUWMbiSY3g2WeK7QyOvk/Y819QsMgoHQZz7fU8Zt7I=" Sep 15 22:32:51 volumio volumio[1076]: info: Getting Spotify volume Sep 15 22:32:51 volumio volumio[1076]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:51 volumio volumio[1076]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 15 22:32:51 volumio volumio[1076]: info: Received Get System Info Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 22:32:51 volumio volumio[1076]: info: Discovery: Getting this device information Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::volumioGetState Sep 15 22:32:51 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=debug msg="completed challenge" Sep 15 22:32:51 volumio go-librespot[8515]: time="2025-09-15T22:32:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:51 volumio volumio[1076]: (node:1076) UnhandledPromiseRejectionWarning: Error: socket hang up Sep 15 22:32:51 volumio volumio[1076]: at connResetException (internal/errors.js:639:14) Sep 15 22:32:51 volumio volumio[1076]: at Socket.socketOnEnd (_http_client.js:499:23) Sep 15 22:32:51 volumio volumio[1076]: at Socket.emit (events.js:412:35) Sep 15 22:32:51 volumio volumio[1076]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 15 22:32:51 volumio volumio[1076]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 15 22:32:51 volumio volumio[1076]: (node:1076) 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: 93204) Sep 15 22:32:51 volumio volumio[1076]: info: Connection to go-librespot Websocket closed Sep 15 22:32:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:52 volumio volumio[1076]: info: Disabling MyMusic plugin upnp Sep 15 22:32:52 volumio sudo[8553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Sep 15 22:32:52 volumio sudo[8553]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 22:32:52 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Sep 15 22:32:52 volumio volumio[1076]: error: Upnp client error: Error: This socket has been ended by the other party Sep 15 22:32:54 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 15 22:32:54 volumio volumio[1076]: info: Initializing connection to go-librespot Websocket Sep 15 22:32:54 volumio volumio[1076]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 15 22:32:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 15 22:32:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522401. Sep 15 22:32:54 volumio systemd[1]: Stopped go-librespot Daemon. Sep 15 22:32:54 volumio systemd[1]: Started go-librespot Daemon. Sep 15 22:32:54 volumio go-librespot[8556]: go-librespot daemon starting... Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=info msg="running go-librespot 0.2.0" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=debug msg="app state loaded" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32: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-gew4.spotify.com:80]" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 15 22:32:54 volumio go-librespot[8556]: time="2025-09-15T22:32:54+07:00" level=info msg="zeroconf server listening on port 38353" Sep 15 22:32:55 volumio go-librespot[8556]: time="2025-09-15T22:32:55+07:00" level=debug msg="obtained new client token: AAAtwDVKPO5jMYZAJWpGuRW6NqUZ4mBtdS71a2xNp+WSyFoWMzYNLHqdEbL7EGyP3zAdzRWIb8RjPF+8TWLhPBr6vWfaioS3sCOQezE4BTk3VTwPu/R2JfOzgTzMInqJ40nuHEbioPNa17W8d/lk5OiV6gzxbyiDFw6H15zppFh4Cirzadse8k0dXa4fclcSTeTFrETcsElF++CD1Aq7f+cONfC/PKH3PAMGAoYXiKFptnaxmyKt5QgF" Sep 15 22:32:55 volumio go-librespot[8556]: time="2025-09-15T22:32:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 15 22:32:55 volumio go-librespot[8556]: time="2025-09-15T22:32:55+07:00" level=debug msg="completed keyexchange" Sep 15 22:32:55 volumio go-librespot[8556]: time="2025-09-15T22:32:55+07:00" level=debug msg="completed challenge" Sep 15 22:32:55 volumio go-librespot[8556]: time="2025-09-15T22:32:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Sep 15 22:32:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 15 22:32:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 15 22:32:57 volumio volumio[1076]: info: Enabling MyMusic plugin upnp Sep 15 22:32:57 volumio volumio[1076]: info: Enabling plugin upnp Sep 15 22:32:57 volumio volumio[1076]: info: Loading plugin "upnp"... Sep 15 22:32:57 volumio volumio[1076]: info: [1757950377409] Starting Upmpd Daemon Sep 15 22:32:57 volumio volumio[1076]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 15 22:32:57 volumio volumio[1076]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 22:32:57 volumio volumio[1076]: Error: listen EADDRINUSE: address already in use :::6599 Sep 15 22:32:57 volumio volumio[1076]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Sep 15 22:32:57 volumio volumio[1076]: at listenInCluster (net.js:1379:12) Sep 15 22:32:57 volumio volumio[1076]: at Server.listen (net.js:1465:7) Sep 15 22:32:57 volumio volumio[1076]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Sep 15 22:32:57 volumio volumio[1076]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Sep 15 22:32:57 volumio volumio[1076]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Sep 15 22:32:57 volumio volumio[1076]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Sep 15 22:32:57 volumio volumio[1076]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Sep 15 22:32:57 volumio volumio[1076]: code: 'EADDRINUSE', Sep 15 22:32:57 volumio volumio[1076]: errno: -98, Sep 15 22:32:57 volumio volumio[1076]: syscall: 'listen', Sep 15 22:32:57 volumio volumio[1076]: address: '::', Sep 15 22:32:57 volumio volumio[1076]: port: 6599 Sep 15 22:32:57 volumio volumio[1076]: } Sep 15 22:32:57 volumio volumio[1076]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 22:32:57 volumio sudo[8586]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-15 22:31 Sep 15 22:32:57 volumio sudo[8586]: 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"