-- Logs begin at Fri 2025-07-04 16:24:02 +07, end at Fri 2025-07-04 18:50:14 +07. -- Jul 04 18:49:00 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:00 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16775. Jul 04 18:49:00 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:00 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:00 volumio2 go-librespot[1256]: Librespot-go daemon starting... Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=info msg="generated new device id: c15e06a2a7751deae47823c05995237dba06fafa" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=debug msg="obtained new client token: AACdYRlb1tPpumHA8QEHeumJTmff0wrLGFnBhhLB3I15OEBtPgZVv2iEYQRHRtYyQovTa+6SO9Rvok+UjcfPty46WmUIN6rL3b+dAp5T64bbOJUjN/1x0DOBrirpu8DPt4CYLITK5E2LFv0ItApAPZMCFc/XdeYJaJVc8uZsglXjeuoLRO7sJw6BOH9M1Cg9gxPX4jLi2687OB8Jw6/aIIXGZU+kQV4U81R1ZmavoBFK7WaJQN9uxadAPQ==" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=debug msg="completed challenge" Jul 04 18:49:00 volumio2 go-librespot[1256]: time="2025-07-04T18:49:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:00 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:00 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:01 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:01 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:04 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:04 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:04 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:04 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16776. Jul 04 18:49:04 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:04 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:04 volumio2 go-librespot[1267]: Librespot-go daemon starting... Jul 04 18:49:04 volumio2 go-librespot[1267]: time="2025-07-04T18:49:04+07:00" level=info msg="generated new device id: 223cfd583950060d806b7917530970bb3d3b491b" Jul 04 18:49:04 volumio2 go-librespot[1267]: time="2025-07-04T18:49:04+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:04 volumio2 go-librespot[1267]: time="2025-07-04T18:49:04+07:00" level=debug msg="obtained new client token: AABLjGWCZrNFOFgiq5fS0IsDNo1a8AbaOQrBk0G+uY0Sp9/U85RgX9Ulf2VMHULv/KJ0HDuUGpGwtGYdhyHk4w5GX1ROsJOfwVDcYssYtz/ehLUjAH64g27VlJQO81XQj+jvhVDUQPC5vfPGawElnSXHIvaIsor0L/EiHeQVrVAn9PUlMzyUVNTuLwFbLkDbhGte86rNIR5g/cyFyL7quXmTrj1iWxcfKZ6VUr3Qv33BxVPLsFIYzmSUOA==" Jul 04 18:49:04 volumio2 go-librespot[1267]: time="2025-07-04T18:49:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:04 volumio2 go-librespot[1267]: time="2025-07-04T18:49:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 04 18:49:04 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:04 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:07 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:07 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:07 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:07 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16777. Jul 04 18:49:07 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:07 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:07 volumio2 go-librespot[1278]: Librespot-go daemon starting... Jul 04 18:49:07 volumio2 go-librespot[1278]: time="2025-07-04T18:49:07+07:00" level=info msg="generated new device id: cdf9bb8550f000693b1ede16609144ce7ef0c9b2" Jul 04 18:49:07 volumio2 go-librespot[1278]: time="2025-07-04T18:49:07+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:07 volumio2 go-librespot[1278]: time="2025-07-04T18:49:07+07:00" level=debug msg="obtained new client token: AAAlQ7HkqNB7F5n0ULyiqiXKN15PbMxhJlwTlg7ZS2p966QppaHzUBHM9ifpUUIyRNl52jUhpv9+ilCCrlwiCV+V3lFurmyTdoNCBQdkZdBzlxrLHCymo4dPeWNfWkY7VOnwoep0c+TW7J560/KmCpiWP/InrRabAxqFqi50VvSefN1805iakVeJzGJ+Re6bERPk2geIfwP9f+5gyvkF3wlkwx5aOfJZk/y3DB14lBk+O7yHMqr+l8Phq07X" Jul 04 18:49:07 volumio2 go-librespot[1278]: time="2025-07-04T18:49: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-gew1.spotify.com:80]" Jul 04 18:49:07 volumio2 go-librespot[1278]: time="2025-07-04T18:49:07+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:08 volumio2 go-librespot[1278]: time="2025-07-04T18:49:08+07:00" level=debug msg="completed challenge" Jul 04 18:49:08 volumio2 go-librespot[1278]: time="2025-07-04T18:49:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:08 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:08 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:10 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:10 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:11 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:11 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16778. Jul 04 18:49:11 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:11 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:11 volumio2 go-librespot[1299]: Librespot-go daemon starting... Jul 04 18:49:11 volumio2 go-librespot[1299]: time="2025-07-04T18:49:11+07:00" level=info msg="generated new device id: e402cc82883f896b4353cc65d9584ee6d908bc6b" Jul 04 18:49:11 volumio2 go-librespot[1299]: time="2025-07-04T18:49:11+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:11 volumio2 go-librespot[1299]: time="2025-07-04T18:49:11+07:00" level=debug msg="obtained new client token: AAAy+vIGrd/w8RjB0tOSqIJFUm6dSdSo54sk4mwnGgpqUABR8JBaSr/pRgTb1DIjCaxAiVS/JC5+Bi9u4SXUTnfuGs2sUxxfBq7ryBTt8jvvfV6hxUwfjzgb632V4thaYkwRE7Tdh/qsyQNcVY+mgkQcVMBg7RvUMpqoCKYzE55Dhq3+Q0w0m6zoVHC9c1Kx5llL0BnxQ6UWfX/8i+4mgUPnTMybU/lOeHdqwisCTSrSUD1m5pJgkm0mkgG2" Jul 04 18:49:11 volumio2 go-librespot[1299]: time="2025-07-04T18:49:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:11 volumio2 go-librespot[1299]: time="2025-07-04T18:49:11+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:12 volumio2 go-librespot[1299]: time="2025-07-04T18:49:12+07:00" level=debug msg="completed challenge" Jul 04 18:49:12 volumio2 go-librespot[1299]: time="2025-07-04T18:49:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:12 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:12 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:13 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:13 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:15 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:15 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16779. Jul 04 18:49:15 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:15 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:15 volumio2 go-librespot[1318]: Librespot-go daemon starting... Jul 04 18:49:15 volumio2 go-librespot[1318]: time="2025-07-04T18:49:15+07:00" level=info msg="generated new device id: 8ad55d39dec74d173e0916680be1aff809720a78" Jul 04 18:49:15 volumio2 go-librespot[1318]: time="2025-07-04T18:49:15+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:15 volumio2 go-librespot[1318]: time="2025-07-04T18:49:15+07:00" level=debug msg="obtained new client token: AABA8h44CEtfswkKh0fpkyUUcGQbYgaIeo8AZ9Xg/IjkFQ7NZUiTs+Qp0k/xd4OZeCg1bicSOFPoV3Twut80ZQm83EX2brmsZTbORXCF7i4LykkkXNZJA72pzfhv39RqD3ZhQOnlIZItd7ewegSvmkkw4lEYQtMCl7f/1xFa+MJSaGGcG7Hr421VE8i5pYGdiHatSAgk6oOW27bdYfU4tohXavW+BbD25mWH4HjMVaRoH2IzI3E5Rv78/OVA" Jul 04 18:49:15 volumio2 go-librespot[1318]: time="2025-07-04T18:49:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:15 volumio2 go-librespot[1318]: time="2025-07-04T18:49:15+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:16 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:16 volumio2 go-librespot[1318]: time="2025-07-04T18:49:16+07:00" level=debug msg="new websocket client" Jul 04 18:49:16 volumio2 volumio[1036]: info: Connection to go-librespot Websocket established Jul 04 18:49:16 volumio2 go-librespot[1318]: time="2025-07-04T18:49:16+07:00" level=debug msg="completed challenge" Jul 04 18:49:16 volumio2 go-librespot[1318]: time="2025-07-04T18:49:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:16 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:16 volumio2 volumio[1036]: info: Connection to go-librespot Websocket closed Jul 04 18:49:16 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:19 volumio2 volumio[1036]: info: Getting Spotify volume Jul 04 18:49:19 volumio2 volumio[1036]: (node:1036) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:19 volumio2 volumio[1036]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 04 18:49:19 volumio2 volumio[1036]: (node:1036) 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: 2200) Jul 04 18:49:19 volumio2 volumio[1036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 04 18:49:19 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:19 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:49:19 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:19 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:19 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:19 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16780. Jul 04 18:49:19 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:19 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:19 volumio2 go-librespot[1363]: Librespot-go daemon starting... Jul 04 18:49:19 volumio2 go-librespot[1363]: time="2025-07-04T18:49:19+07:00" level=info msg="generated new device id: 6743cd1cb15c96a4fad58dc35b84cd17aa1366b9" Jul 04 18:49:19 volumio2 go-librespot[1363]: time="2025-07-04T18:49:19+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:19 volumio2 go-librespot[1363]: time="2025-07-04T18:49:19+07:00" level=debug msg="obtained new client token: AABiNIcvdyKHl3MHs7LlMzOW6Sc4yEZlGk/fOhDPnuf0N0LLfHSKF1teUeGilF73oQTfTlafK6Ey1T1XaFAkGd3oEWn3hKT3yD/rXQZ/KfTzGSAn7Z3v0DpS0izwtrb9LJTGscF1q7uNsaSIoHf5Op9Msn0IlBYbW4D1wIYcdYjWAnHqAkV9KVU/789lZ+cYAVNPul99cteGggGwMonwpL66QlRf2IM7bUvxqVKd+BuWTGIQYyHcW+2qpkfn" Jul 04 18:49:19 volumio2 go-librespot[1363]: time="2025-07-04T18:49:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 04 18:49:19 volumio2 go-librespot[1363]: time="2025-07-04T18:49:19+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:20 volumio2 go-librespot[1363]: time="2025-07-04T18:49:20+07:00" level=debug msg="completed challenge" Jul 04 18:49:20 volumio2 go-librespot[1363]: time="2025-07-04T18:49:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:20 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:20 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:22 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:22 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:23 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:23 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16781. Jul 04 18:49:23 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:23 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:23 volumio2 go-librespot[1372]: Librespot-go daemon starting... Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=info msg="generated new device id: 5ffff06553f93ac6aa806718d359408fb4c87a53" Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=debug msg="obtained new client token: AACuPrhAVUakxeJdSyf4RtO/ecXF5lRHZHH1tTdprpxCJ0st3tUk/gSNhuCxLxy0FcuOG77VXraIw6d43F/nlOqRjepOLvUHX1LAmUQ2Ki3t/gMgPjMVALYIB0T1sZHIMqpNEznl7tST2I3bxanpnWyQqn2SqveLeb8bWuLX9WiU1jEGfyePKkSJOOJQhcWqewo4+8zDck/S1UXKvNQMq2glpHxrQ37jwPXegHMEL6Ox3rWCmyOoylWw+/e9" Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:23 volumio2 go-librespot[1372]: time="2025-07-04T18:49:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed solving challenge: failed login: BadCredentials" Jul 04 18:49:23 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:23 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:25 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:25 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:27 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:27 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16782. Jul 04 18:49:27 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:27 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:27 volumio2 go-librespot[1385]: Librespot-go daemon starting... Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=info msg="generated new device id: f6fd1b2d5abd1613605f7d0fce9913ce73c11b45" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=debug msg="obtained new client token: AAAWpnU5De3Uu7G5rfJlu9Mp0vgO81BNuD1s+6f/p6MP2NyllCx/YMsiaDgsZGO9DEM+qHyyxgrccBRk8/AsmvJW9e+xyJ1XnHtWiU5v5Z7AIrB1FYZj/1si3l4LT6ne5QWv4KpiEbWaHnk1622vxQp5Pm92vCuv2y23tXvyCy3WSiRBwrG5sWGVDLbZhsDfqjsemNRyeLN4FofCqwZYOxX1qbfaQosfgpNWc7uSLoMgrwHrHFbUVlCXtQ==" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=debug msg="completed challenge" Jul 04 18:49:27 volumio2 go-librespot[1385]: time="2025-07-04T18:49:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:27 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:27 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:28 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:28 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:31 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:31 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16783. Jul 04 18:49:31 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:31 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:31 volumio2 go-librespot[1413]: Librespot-go daemon starting... Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=info msg="generated new device id: 1641146a2d654347e1d988f34791402a03268912" Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="obtained new client token: AADKZEsqacaJ2Dc4VhZRGeN5zYhspgggVa5+42P4nOWn7Wd6DnWq1Hfd/TlyY8PqLL4CTZZFU3Qw82ClE4/7Gv1zeq5nWOmSxG0NRslFCtm2VGr9d2VOaaDAPwn4UP31Lq34drweBqFUuNNwZCLRMgpkif+FsetGnv+6ECxamZMeOBv0htgepBIB4UlCGLnhEQbefx8i0av1FjBNYuxSztwa8rCwEVYtxwuE/gmfyxTXkOL8tLXmKOiv/A==" Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:31 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="new websocket client" Jul 04 18:49:31 volumio2 volumio[1036]: info: Connection to go-librespot Websocket established Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=debug msg="completed challenge" Jul 04 18:49:31 volumio2 go-librespot[1413]: time="2025-07-04T18:49:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:31 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:31 volumio2 volumio[1036]: info: Connection to go-librespot Websocket closed Jul 04 18:49:31 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:34 volumio2 volumio[1036]: info: Getting Spotify volume Jul 04 18:49:34 volumio2 volumio[1036]: (node:1036) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:34 volumio2 volumio[1036]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 04 18:49:34 volumio2 volumio[1036]: (node:1036) 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: 2201) Jul 04 18:49:34 volumio2 volumio[1036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 04 18:49:34 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:34 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:49:34 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:34 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:35 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:35 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16784. Jul 04 18:49:35 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:35 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:35 volumio2 go-librespot[1421]: Librespot-go daemon starting... Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=info msg="generated new device id: 12284c68883c61e6d2fe1f31c8a9787b98b8f245" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=debug msg="obtained new client token: AAB9Cq5yJ1DcIUCvq5ztJMyITbsKBRKDLRdtr0htObs/20Cfb2uyMWis2Vd5IjbOEnhP7dcfSG4+SloeWVujVjER3YhoI9lgPZkHox8UhaO5fgn12YJBf49K7gSIaAZB2UrX7H3nfIMV+TuLboACMknn/a6TqsMraOTzKhiRpLeWYA1Bz5mBAebPmYu+2DZWclIisvWnVZAZd7WfQRVU0rRFNy+26bICaceOkyCCOVZ4CVaIGpm+7i5+eg==" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=debug msg="completed challenge" Jul 04 18:49:35 volumio2 go-librespot[1421]: time="2025-07-04T18:49:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:35 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:35 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 18:49:37 volumio2 volumio[1036]: info: Discovery: Getting this device information Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 18:49:37 volumio2 volumio[1036]: verbose: New Socket.io Connection to 192.168.1.43:3000 from 192.168.1.20 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 04 18:49:37 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 04 18:49:37 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:37 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:39 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:39 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16785. Jul 04 18:49:39 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:39 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:39 volumio2 go-librespot[1449]: Librespot-go daemon starting... Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=info msg="generated new device id: eef1d3d38c22aa6b7c588ad2bd778d670b00926c" Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=debug msg="obtained new client token: AAB83Qr3nCn3CIFh0xMQgKDF9kJ+eJz30VBbH7hnHjP2cm6XeVgFtEFBBedZY5r+f+9xRkIKQjIti9+hbjD1de+uTcuyncbh97YqTyM7MQ9aFJXkwKhe5gHDeGpqIGcsVfxz9PpdcivRgTaHX0jd9VWs/dk3eWG5FoCVTgDwklttJcWdNc0N535CJXQysHr2a4zOktNWeVaKJ9OJ6Qs5KejTiBSaVYmCXqA684uo2w3SglotpNN3nMUSZw==" Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:39 volumio2 sudo[1480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 18:49:39 volumio2 sudo[1480]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:39 volumio2 sudo[1480]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:39 volumio2 sudo[1483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 18:49:39 volumio2 sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:39 volumio2 sudo[1483]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:39 volumio2 volumio[1036]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=debug msg="completed challenge" Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 04 18:49:39 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 04 18:49:39 volumio2 go-librespot[1449]: time="2025-07-04T18:49:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:39 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:39 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:40 volumio2 sudo[1486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 18:49:40 volumio2 sudo[1486]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:40 volumio2 sudo[1486]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:40 volumio2 sudo[1489]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 18:49:40 volumio2 sudo[1489]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:40 volumio2 sudo[1489]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:40 volumio2 volumio[1036]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.20 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 04 18:49:40 volumio2 volumio[1036]: info: Listing playlists Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 04 18:49:40 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 04 18:49:40 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:40 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:41 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 18:49:41 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 18:49:41 volumio2 volumio[1036]: info: Discovery: Getting this device information Jul 04 18:49:41 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:41 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 18:49:42 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 18:49:42 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 18:49:42 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetQueue Jul 04 18:49:42 volumio2 volumio[1036]: info: CoreStateMachine::getQueue Jul 04 18:49:42 volumio2 volumio[1036]: info: CorePlayQueue::getQueue Jul 04 18:49:43 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:43 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16786. Jul 04 18:49:43 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:43 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:43 volumio2 go-librespot[1491]: Librespot-go daemon starting... Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=info msg="generated new device id: 2184f96ccec6e40814572cf5ca60f4600dbfa536" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=debug msg="obtained new client token: AACnKTPG7MUD+J+dSi+Y42cPYXifAeRXhTZ+yAF8RRtbkgkXDB3CYtfnzpSienjbBAiUWxepHf2WS4XsKn0I9vFhq5urr/fmOWbhNDX+bIRStvJWZubFASX/+DUXBka9j6CazBpGWuVWu+cxPhA5tyQ45bq9+KKMLqUXLnaDQVia2KUZQ5VgC57EFztXBlgQ6dHiAGSCysnUTzSyL4vKGOCpknRt4Yw6T4M7NJzbBcx3LfanS6YbkR5E+w==" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=debug msg="completed challenge" Jul 04 18:49:43 volumio2 go-librespot[1491]: time="2025-07-04T18:49:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:43 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:43 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:43 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:43 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 04 18:49:45 volumio2 volumio[1036]: info: Received Get System Info Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 18:49:45 volumio2 volumio[1036]: info: Discovery: Getting this device information Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:45 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 18:49:46 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:46 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:47 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:47 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16787. Jul 04 18:49:47 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:47 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:47 volumio2 go-librespot[1502]: Librespot-go daemon starting... Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=info msg="generated new device id: c6e7d5ef7f23d16b5c688b8a2c537ee8d4c8b1ac" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=debug msg="obtained new client token: AAA3wJsYbeWz2GPiFv56rXaBbVfSta3AAPIkL5aIF+6PEGf4PgjaZJQNrP7SeQl/lLDPA/OmBZCA2dqxzfgB8oD0ySDPOk+pzlCk+s0cVcPUMOD631/huvi+qhokSU0ljdpPwcPue2HZyUoGfkjVpajnRn4PJ819LaEsfX3Ci38wsl0/bq4KrndXGy3eaxNn3sAy1JQpmDAE/Nu9bPH8DLRXCxmMZ+ISQZrei9ZcvY8k9JTnaBxOCwnGXA==" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=debug msg="completed challenge" Jul 04 18:49:47 volumio2 go-librespot[1502]: time="2025-07-04T18:49:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:47 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:47 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:49 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:49 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:51 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:51 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16788. Jul 04 18:49:51 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:51 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:51 volumio2 go-librespot[1528]: Librespot-go daemon starting... Jul 04 18:49:51 volumio2 go-librespot[1528]: time="2025-07-04T18:49:51+07:00" level=info msg="generated new device id: 37c825f7b348bea393f4b8872e076b039aa5aca5" Jul 04 18:49:51 volumio2 go-librespot[1528]: time="2025-07-04T18:49:51+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:51 volumio2 go-librespot[1528]: time="2025-07-04T18:49:51+07:00" level=debug msg="obtained new client token: AACj1PsW6A92rco+wXSLfHA8XKmF5Mn3S5m6sOUS66ZOmQOFNjSRMTLKAQiJCZDhWhXNWO96fObX/O8E1PJnEuSpvk1eJ45i1mzk5LfzprzRK4RoV/cpXBXUs7DaXR34rU8z2ryvh6b3e4NH1HzpD8ikxtnTsH6Mvx+xDCc76+sFMAECSubj6AmdssEJg2HeeEqsXZHkjiN0QKrLnAoAMzUDEYkN8RRt7BwWEfz2TKqNGdxQtSCjgRBS0w==" Jul 04 18:49:51 volumio2 go-librespot[1528]: time="2025-07-04T18:49: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]" Jul 04 18:49:51 volumio2 go-librespot[1528]: time="2025-07-04T18:49:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Jul 04 18:49:51 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:51 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:51 volumio2 volumio[1036]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jul 04 18:49:51 volumio2 volumio[1036]: info: Preparing to save Alsa Options, stopping services first Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::volumioPause Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreStateMachine::pause Jul 04 18:49:51 volumio2 volumio[1036]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB Audio DAC"}} Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 18:49:51 volumio2 volumio[1036]: info: Setting mixer PCM for card USB Audio DAC Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 04 18:49:51 volumio2 volumio[1036]: info: Updating Volume Controller Parameters: Device: 5 Name: USB Audio DAC Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 04 18:49:51 volumio2 volumio[1036]: info: Disabling external Volume Control Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:49:51 volumio2 volumio[1036]: info: Preparing to generate the ALSA configuration file Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 18:49:51 volumio2 volumio[1036]: info: Asound.conf file unchanged, so no further update is needed Jul 04 18:49:51 volumio2 volumio[1036]: info: Output device has changed, restarting MPD Jul 04 18:49:51 volumio2 sudo[1553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 18:49:51 volumio2 sudo[1553]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:51 volumio2 volumio[1036]: info: Output device has changed, restarting Shairport Sync Jul 04 18:49:51 volumio2 sudo[1553]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 18:49:51 volumio2 sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 18:49:51 volumio2 sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:51 volumio2 systemd[1]: Stopping Music Player Daemon... Jul 04 18:49:51 volumio2 volumio[1036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 18:49:51 volumio2 systemd[1]: mpd.service: Succeeded. Jul 04 18:49:51 volumio2 systemd[1]: Stopped Music Player Daemon. Jul 04 18:49:51 volumio2 volumio[1036]: info: MPD Permissions set Jul 04 18:49:51 volumio2 volumio[1036]: info: VolumeController:: Volume=100 Mute =false Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreStateMachine::pushState Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::volumioPushState Jul 04 18:49:51 volumio2 systemd[1]: Starting Music Player Daemon... Jul 04 18:49:51 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 18:49:51 volumio2 sudo[1562]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 18:49:51 volumio2 sudo[1562]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:51 volumio2 sudo[1562]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:51 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 18:49:51 volumio2 volumio[1036]: info: Starting Shairport Sync Jul 04 18:49:52 volumio2 sudo[1573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 18:49:52 volumio2 sudo[1573]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:49:52 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 04 18:49:52 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jul 04 18:49:52 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 04 18:49:52 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 04 18:49:52 volumio2 sudo[1573]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:52 volumio2 volumio[1036]: info: Shairport-Sync Started Jul 04 18:49:52 volumio2 mpd[1571]: Jul 04 18:49 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 18:49:52 volumio2 systemd[1]: Started Music Player Daemon. Jul 04 18:49:52 volumio2 sudo[1556]: pam_unix(sudo:session): session closed for user root Jul 04 18:49:52 volumio2 volumio[1036]: error: updateQueue error: null Jul 04 18:49:52 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:53 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:54 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:54 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16789. Jul 04 18:49:54 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:54 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:54 volumio2 go-librespot[1634]: Librespot-go daemon starting... Jul 04 18:49:54 volumio2 go-librespot[1634]: time="2025-07-04T18:49:54+07:00" level=info msg="generated new device id: 73c77c4fde3fdbd3e97deef75571d094916d75a4" Jul 04 18:49:54 volumio2 go-librespot[1634]: time="2025-07-04T18:49:54+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:54 volumio2 go-librespot[1634]: time="2025-07-04T18:49:54+07:00" level=debug msg="obtained new client token: AABz5/0mXw3Std39d1hVlC4/3ukxnqcFqSYyZvgPJT6mAQrkXOWz+LJu/ovzRylHqLJQcQwjU/7IPgebztCYIsmlwgDMSEDE/NjJ+WnmbBnRt+Ls0jjZtfka07ULYSrjexaFZ2wJIjjafdAbMbdxnlkQ9ZOO5ns8Y06TTBRpbAXXL58sd1KjRWc+VmbTYCWt76pqsOFw2i/Cpa0z31XzGAmsbGp17HbihKQuzXcitPeUaLNOsvO9Bked30Uj" Jul 04 18:49:54 volumio2 go-librespot[1634]: time="2025-07-04T18:49: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]" Jul 04 18:49:54 volumio2 go-librespot[1634]: time="2025-07-04T18:49:54+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:55 volumio2 go-librespot[1634]: time="2025-07-04T18:49:55+07:00" level=debug msg="completed challenge" Jul 04 18:49:55 volumio2 go-librespot[1634]: time="2025-07-04T18:49:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:55 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:55 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreStateMachine::getcurrentVolume Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreCommandRouter::volumioRetrievevolume Jul 04 18:49:55 volumio2 volumio[1036]: info: VolumeController:: Volume=100 Mute =false Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreStateMachine::pushState Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreCommandRouter::volumioPushState Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreStateMachine::updateTrackBlock Jul 04 18:49:55 volumio2 volumio[1036]: info: CorePlayQueue::getTrackBlock Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreCommandRouter::volumioRetrievevolume Jul 04 18:49:55 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:49:55 volumio2 volumio[1036]: info: VolumeController:: Volume=100 Mute =false Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreStateMachine::pushState Jul 04 18:49:55 volumio2 volumio[1036]: info: CoreCommandRouter::volumioPushState Jul 04 18:49:55 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:49:56 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:56 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:49:58 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:49:58 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16790. Jul 04 18:49:58 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:49:58 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:49:58 volumio2 go-librespot[1655]: Librespot-go daemon starting... Jul 04 18:49:58 volumio2 go-librespot[1655]: time="2025-07-04T18:49:58+07:00" level=info msg="generated new device id: 4cb94fc93ba6bb6e3b712b0b38ed43b477d15b29" Jul 04 18:49:58 volumio2 go-librespot[1655]: time="2025-07-04T18:49:58+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:49:58 volumio2 go-librespot[1655]: time="2025-07-04T18:49:58+07:00" level=debug msg="obtained new client token: AADCEOdc49TekzKVLqnPgiM0dQRiwGez60fz5PLkaFFhhZFQEPjftMJ3EjmaB5z73rl9xJ1ZXYe4DlMM1G7YyPGIv1PVRJ2zpztP9DLzYVHueKO7+zgp6MUeqST/a/kf9I9B1EFYsO2ALqz9uE9e5hUv48jjql7O7O5mZvYiNRObuaP61yQMYn9gdufPfHZVx0aXfGkTNttuOrmnpy9yUORXOpDILfohWTbTTq++tCgyc6atFpXEd4opTIJS" Jul 04 18:49:58 volumio2 go-librespot[1655]: time="2025-07-04T18:49:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:49:58 volumio2 go-librespot[1655]: time="2025-07-04T18:49:58+07:00" level=debug msg="completed keyexchange" Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 04 18:49:58 volumio2 volumio[1036]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 04 18:49:58 volumio2 volumio[1036]: info: Received Get System Version Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 18:49:58 volumio2 volumio[1036]: info: Received Get System Info Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 18:49:58 volumio2 volumio[1036]: info: Discovery: Getting this device information Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:49:58 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 18:49:59 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:49:59 volumio2 volumio[1036]: info: Connection to go-librespot Websocket established Jul 04 18:49:59 volumio2 go-librespot[1655]: time="2025-07-04T18:49:59+07:00" level=debug msg="new websocket client" Jul 04 18:49:59 volumio2 go-librespot[1655]: time="2025-07-04T18:49:59+07:00" level=debug msg="completed challenge" Jul 04 18:49:59 volumio2 go-librespot[1655]: time="2025-07-04T18:49:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:49:59 volumio2 volumio[1036]: info: Connection to go-librespot Websocket closed Jul 04 18:49:59 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:49:59 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:50:02 volumio2 volumio[1036]: info: Getting Spotify volume Jul 04 18:50:02 volumio2 volumio[1036]: (node:1036) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:50:02 volumio2 volumio[1036]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 04 18:50:02 volumio2 volumio[1036]: (node:1036) 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: 2202) Jul 04 18:50:02 volumio2 volumio[1036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 04 18:50:02 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:50:02 volumio2 volumio[1036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 04 18:50:02 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:50:02 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:50:02 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:50:02 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16791. Jul 04 18:50:02 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:50:02 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:50:02 volumio2 go-librespot[1690]: Librespot-go daemon starting... Jul 04 18:50:02 volumio2 go-librespot[1690]: time="2025-07-04T18:50:02+07:00" level=info msg="generated new device id: 79d80d1dcd248549c1d1e72a58ee024405a87d8a" Jul 04 18:50:02 volumio2 go-librespot[1690]: time="2025-07-04T18:50:02+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:50:02 volumio2 go-librespot[1690]: time="2025-07-04T18:50:02+07:00" level=debug msg="obtained new client token: AAArfQ7bVTtuOPswmz71T7zeNdP0MlpElPtqc7moh6PovajuloEtL4k8rhiQxwwemkk1dN25rHz8lUYXwdcdlUP7uTJXrSpWEoSdlP+/z3vYtTFMoLfr+gn0pcq30YsAXN1/nyGCvSVcgjfE/9ShR+mzVKvPtjWlc1CxatfDEuAjUPT0rEB+9uXJLjT1HL7ihFarqN68Jd8E2PGjPFDZAZOSdsjBVQNC9lLNPqbJb/LKt8SwNdOwvuimJ+Ji" Jul 04 18:50:02 volumio2 go-librespot[1690]: time="2025-07-04T18:50:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 04 18:50:03 volumio2 go-librespot[1690]: time="2025-07-04T18:50:03+07:00" level=debug msg="completed keyexchange" Jul 04 18:50:03 volumio2 go-librespot[1690]: time="2025-07-04T18:50:03+07:00" level=debug msg="completed challenge" Jul 04 18:50:03 volumio2 go-librespot[1690]: time="2025-07-04T18:50:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:50:03 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:50:03 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 04 18:50:04 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 18:50:05 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:50:05 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 18:50:06 volumio2 volumio[1036]: info: Discovery: Getting this device information Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetState Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 18:50:06 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:50:06 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16792. Jul 04 18:50:06 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:50:06 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:50:06 volumio2 go-librespot[1702]: Librespot-go daemon starting... Jul 04 18:50:06 volumio2 go-librespot[1702]: time="2025-07-04T18:50:06+07:00" level=info msg="generated new device id: 4818738a8cd1d1835ab26ad6f484e0a87147971b" Jul 04 18:50:06 volumio2 go-librespot[1702]: time="2025-07-04T18:50:06+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: info: Retrieving Cloud Streaming UI Jul 04 18:50:06 volumio2 volumio[1036]: info: Getting Tidal Cloud Configuration Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: info: Getting Qobuz Cloud Configuration Jul 04 18:50:06 volumio2 volumio[1036]: info: Asking plugin for UI Config Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: info: Getting Spotify Cloud Configuration Jul 04 18:50:06 volumio2 volumio[1036]: info: Asking plugin for UI Config Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: info: Saving Spotify Acccount Jul 04 18:50:06 volumio2 volumio[1036]: info: Got Tidal Cloud Configuration Jul 04 18:50:06 volumio2 volumio[1036]: info: Got it Jul 04 18:50:06 volumio2 volumio[1036]: info: Got it Jul 04 18:50:06 volumio2 volumio[1036]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 18:50:06 volumio2 volumio[1036]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 18:50:06 volumio2 go-librespot[1702]: time="2025-07-04T18:50:06+07:00" level=debug msg="obtained new client token: AAAk/10WGwTVYd3uWJ8GKVgQZBTQ9zIaX2FZkuSs0fifooTSfK5AYXBuWrkTJyN5fNuLS/Kr7htY2iEj/07MeFW+xrcsmYDHfqtLrzv2lMfhzv0M8XHjpkZeDxrLWpxOs94m/nLZ7W+TxU6ruF+aOHuCf3OjDYtg5ERuXq4SGBaK415awbMnHSLS2aTXIv+pgO1pMyOwLIISInEsN0BdN7n9Edm3SCyzjkpEEtzrC26ukmZY38bpWDaZjTma" Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 04 18:50:06 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 04 18:50:06 volumio2 go-librespot[1702]: time="2025-07-04T18:50: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]" Jul 04 18:50:06 volumio2 go-librespot[1702]: time="2025-07-04T18:50:06+07:00" level=debug msg="completed keyexchange" Jul 04 18:50:07 volumio2 go-librespot[1702]: time="2025-07-04T18:50:07+07:00" level=debug msg="completed challenge" Jul 04 18:50:07 volumio2 go-librespot[1702]: time="2025-07-04T18:50:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:50:07 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:50:07 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:50:08 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:50:08 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:50:08 volumio2 volumio[1036]: info: Disabling MyMusic plugin upnp Jul 04 18:50:08 volumio2 sudo[1710]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jul 04 18:50:08 volumio2 sudo[1710]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 04 18:50:08 volumio2 systemd[1]: Stopping UPnP Renderer front-end to MPD... Jul 04 18:50:08 volumio2 volumio[1036]: error: Upnp client error: Error: This socket has been ended by the other party Jul 04 18:50:10 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 04 18:50:10 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16793. Jul 04 18:50:10 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 04 18:50:10 volumio2 systemd[1]: Started go-librespot Daemon. Jul 04 18:50:10 volumio2 go-librespot[1726]: Librespot-go daemon starting... Jul 04 18:50:10 volumio2 go-librespot[1726]: time="2025-07-04T18:50:10+07:00" level=info msg="generated new device id: 8409c8b58f22dc61dedc10cf1d905495c172486a" Jul 04 18:50:10 volumio2 go-librespot[1726]: time="2025-07-04T18:50:10+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 04 18:50:10 volumio2 go-librespot[1726]: time="2025-07-04T18:50:10+07:00" level=debug msg="obtained new client token: AABP+qfCM7kSwbz7tiGIThnr1SYiFo4DXP44o6sl8LVWsvl0mwlShzlSN0Cm7KckEiHytC/Ah8VpLQh/gs2ZAprLT/UmHmV2dOwP8vn90wRnUedHvaIRW0XeTmZL8Vug0y1PmtVfmTarvBByQd9J0KuQycheEE/8bP1ex2u4iIMN/nh21CfasTtaLOqRfmsTbFVrywqXqcPxq9CUdNMHzDw6RIM5ntYkq30k+K7p+KzPE+1EfIxtkUzetRlv" Jul 04 18:50:10 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 04 18:50:10 volumio2 go-librespot[1726]: time="2025-07-04T18:50:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 04 18:50:10 volumio2 go-librespot[1726]: time="2025-07-04T18:50:10+07:00" level=debug msg="completed keyexchange" Jul 04 18:50:11 volumio2 go-librespot[1726]: time="2025-07-04T18:50:11+07:00" level=debug msg="completed challenge" Jul 04 18:50:11 volumio2 go-librespot[1726]: time="2025-07-04T18:50:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 04 18:50:11 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 18:50:11 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 18:50:11 volumio2 volumio[1036]: info: Initializing connection to go-librespot Websocket Jul 04 18:50:11 volumio2 volumio[1036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 18:50:13 volumio2 volumio[1036]: info: Enabling MyMusic plugin upnp Jul 04 18:50:13 volumio2 volumio[1036]: info: Enabling plugin upnp Jul 04 18:50:13 volumio2 volumio[1036]: info: Loading plugin "upnp"... Jul 04 18:50:13 volumio2 volumio[1036]: info: [1751629813962] Starting Upmpd Daemon Jul 04 18:50:13 volumio2 volumio[1036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 18:50:13 volumio2 volumio[1036]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 18:50:13 volumio2 volumio[1036]: Error: listen EADDRINUSE: address already in use :::6599 Jul 04 18:50:13 volumio2 volumio[1036]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jul 04 18:50:13 volumio2 volumio[1036]: at listenInCluster (net.js:1379:12) Jul 04 18:50:13 volumio2 volumio[1036]: at Server.listen (net.js:1465:7) Jul 04 18:50:13 volumio2 volumio[1036]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jul 04 18:50:13 volumio2 volumio[1036]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jul 04 18:50:13 volumio2 volumio[1036]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jul 04 18:50:13 volumio2 volumio[1036]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 04 18:50:13 volumio2 volumio[1036]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jul 04 18:50:13 volumio2 volumio[1036]: code: 'EADDRINUSE', Jul 04 18:50:13 volumio2 volumio[1036]: errno: -98, Jul 04 18:50:13 volumio2 volumio[1036]: syscall: 'listen', Jul 04 18:50:13 volumio2 volumio[1036]: address: '::', Jul 04 18:50:13 volumio2 volumio[1036]: port: 6599 Jul 04 18:50:13 volumio2 volumio[1036]: } Jul 04 18:50:13 volumio2 volumio[1036]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 18:50:14 volumio2 sudo[1742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-04 18:49 Jul 04 18:50:14 volumio2 sudo[1742]: 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"