-- Logs begin at Thu 2025-07-03 16:13:09 +07, end at Thu 2025-07-03 18:48:28 +07. -- Jul 03 18:47:01 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:01 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:02 volumio2 volumio[1028]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 03 18:47:02 volumio2 volumio[1028]: info: CoreStateMachine::getcurrentVolume Jul 03 18:47:02 volumio2 volumio[1028]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 18:47:02 volumio2 volumio[1028]: info: CoreStateMachine::pushState Jul 03 18:47:02 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:02 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPushState Jul 03 18:47:02 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:02 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15348. Jul 03 18:47:02 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:02 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:02 volumio2 go-librespot[32543]: Librespot-go daemon starting... Jul 03 18:47:02 volumio2 go-librespot[32543]: time="2025-07-03T18:47:02+07:00" level=info msg="generated new device id: 2f3b4747bc5b505c69535cf421779d81c293cd05" Jul 03 18:47:02 volumio2 go-librespot[32543]: time="2025-07-03T18:47:02+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:03 volumio2 go-librespot[32543]: time="2025-07-03T18:47:03+07:00" level=debug msg="obtained new client token: AABcmsjIhp0JPT8phOgZZXeM8kb3zaBRaguLAmFPuY9QB6ReCtJOgrnEjdO00LhOYs2aOCAu38XWUYrpFyhmN+AssW3hhGdyrcKGBI265dZWJHMZa3qm0VAu1dNUDJ/Zz627VInwPmR787A1x4glsf6fvQUn1qSa5/c7TJ0dsKvlZSngCTb8plWy0PLI5TaJB8DVe5puOkW++p8la6TUn9MDPkn3SBxk25oD2sdZcsHGl5l3WBo+7PbDIQ==" Jul 03 18:47:03 volumio2 go-librespot[32543]: time="2025-07-03T18:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:03 volumio2 go-librespot[32543]: time="2025-07-03T18:47:03+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:03 volumio2 go-librespot[32543]: time="2025-07-03T18:47:03+07:00" level=debug msg="completed challenge" Jul 03 18:47:03 volumio2 go-librespot[32543]: time="2025-07-03T18:47: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 03 18:47:03 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:03 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:04 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:04 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:06 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:06 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15349. Jul 03 18:47:06 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:06 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:06 volumio2 go-librespot[32553]: Librespot-go daemon starting... Jul 03 18:47:06 volumio2 go-librespot[32553]: time="2025-07-03T18:47:06+07:00" level=info msg="generated new device id: b87480df17d2cab576cd41c9464205f4f433c130" Jul 03 18:47:06 volumio2 go-librespot[32553]: time="2025-07-03T18:47:06+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:07 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47:07+07:00" level=debug msg="new websocket client" Jul 03 18:47:07 volumio2 volumio[1028]: info: Connection to go-librespot Websocket established Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47:07+07:00" level=debug msg="obtained new client token: AACWTYx2t4adMMRcyd6/rIr3JkYshFuCYibKOIaWGiygtt5oRG3+I948J8F3fjOgOKBNKeRC7mAKDdjvaPnGECLMRKTLbAfssLiD9h7KUtZhTcwLXHFL3d0lz/ye7KlhW1ILU0m5ZaePpXC5llWz8kZzqG3jcauMwLlyIkTM9L3Px7BwlBmKU2MuQE8a4gni53agYImCqvhZ7Qq01BzBhFn8ZQJE23ovZXsR+CcJ9e4XpRuhM4IaWdPq6g==" Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47: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]" Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47:07+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47:07+07:00" level=debug msg="completed challenge" Jul 03 18:47:07 volumio2 go-librespot[32553]: time="2025-07-03T18:47: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 03 18:47:07 volumio2 volumio[1028]: info: Connection to go-librespot Websocket closed Jul 03 18:47:07 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:07 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:10 volumio2 volumio[1028]: info: Getting Spotify volume Jul 03 18:47:10 volumio2 volumio[1028]: (node:1028) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:10 volumio2 volumio[1028]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 03 18:47:10 volumio2 volumio[1028]: (node:1028) 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: 1885) Jul 03 18:47:10 volumio2 volumio[1028]: 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 03 18:47:10 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:10 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:10 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:10 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:10 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:10 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15350. Jul 03 18:47:10 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:10 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:10 volumio2 go-librespot[32574]: Librespot-go daemon starting... Jul 03 18:47:10 volumio2 go-librespot[32574]: time="2025-07-03T18:47:10+07:00" level=info msg="generated new device id: e4d63a3f9ab3236b8c7021157fd7988b1cf6745c" Jul 03 18:47:10 volumio2 go-librespot[32574]: time="2025-07-03T18:47:10+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:11 volumio2 go-librespot[32574]: time="2025-07-03T18:47:11+07:00" level=debug msg="obtained new client token: AAAUZqaotXzDMwJz/1LS+ZnLcz3qLSqP8ceTKRZKP/oGp7/Kod6IoMBElRpF5sD4o1C8Jlnp0X19vs0Hv6PjWnxvw8YrZK1dXGow6hOCf9srTIXL1VoE84YpyPlpFogAr8c+ufO0JcmK+ofhD6ZXQgJP5pvh0JVNSBtpMDzV3mKuMLG+uiOKnvWl3gseW8vkiZLRDfg5JxE1BJB5FO7LAhdwNbrwcDCpBDGywDYyzktooEtfTW2QycZinw==" Jul 03 18:47:11 volumio2 go-librespot[32574]: time="2025-07-03T18:47:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:11 volumio2 go-librespot[32574]: time="2025-07-03T18:47:11+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:11 volumio2 go-librespot[32574]: time="2025-07-03T18:47:11+07:00" level=debug msg="completed challenge" Jul 03 18:47:11 volumio2 go-librespot[32574]: time="2025-07-03T18:47: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 03 18:47:11 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:11 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:13 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:13 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:14 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:14 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15351. Jul 03 18:47:14 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:14 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:14 volumio2 go-librespot[32581]: Librespot-go daemon starting... Jul 03 18:47:14 volumio2 go-librespot[32581]: time="2025-07-03T18:47:14+07:00" level=info msg="generated new device id: 7da58a3026de67cec0251313b7126d3576b99685" Jul 03 18:47:14 volumio2 go-librespot[32581]: time="2025-07-03T18:47:14+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:15 volumio2 go-librespot[32581]: time="2025-07-03T18:47:15+07:00" level=debug msg="obtained new client token: AAAHgT0UkS4VQkVaajZjAhdZXfflRix2t7xReJcsNzi5aribRXqhUibDHEkPG/pEL8djcQAoUy/4+iukHSDpUZ/PLyXWIBtY8Is0ioYfBCVaubQPCTSPHTVeLNdmw52FPBNQYtYXw/shIrtr82C8/1gww9pcgs6P7i3KvXrCeh7YPf91WT0B28pmxnVTPv76xou7Mz45/UXk4AUBMdvuxMdtENOCE61TYwF448iZLkvpWocJKRcKh2Ugzw==" Jul 03 18:47:15 volumio2 go-librespot[32581]: time="2025-07-03T18:47:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:15 volumio2 go-librespot[32581]: time="2025-07-03T18:47:15+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:15 volumio2 go-librespot[32581]: time="2025-07-03T18:47:15+07:00" level=debug msg="completed challenge" Jul 03 18:47:15 volumio2 go-librespot[32581]: time="2025-07-03T18:47:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 03 18:47:15 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:15 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:16 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:16 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:18 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:18 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15352. Jul 03 18:47:18 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:18 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:18 volumio2 go-librespot[32602]: Librespot-go daemon starting... Jul 03 18:47:18 volumio2 go-librespot[32602]: time="2025-07-03T18:47:18+07:00" level=info msg="generated new device id: dad5807007f653b8767a35d02e6d040273449244" Jul 03 18:47:18 volumio2 go-librespot[32602]: time="2025-07-03T18:47:18+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:19 volumio2 go-librespot[32602]: time="2025-07-03T18:47:19+07:00" level=debug msg="obtained new client token: AAAbLbMR1QRzVpyYJeny9mhSez1cg9qLXPysRS1SSsCfjFjItlPUCLq8uiw7FTxtGCFowMsb+Sd/Ie1bP6BYFN7CS6KJYuxZTePvkzTHiMa8zystZL8BpQJVc3zREp9RFyR4m+5+6gx/mllUTK0cdnR6jWql2DLFsT0YCXJITNvSsNGzMQrQs8N3DHMReJltXjzC/8CQNuIm+Aq3TvbFPJvXJmf3reU37LCvlQjgBCUsr+G7VC117Hi9yQ==" Jul 03 18:47:19 volumio2 go-librespot[32602]: time="2025-07-03T18:47:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:19 volumio2 go-librespot[32602]: time="2025-07-03T18:47:19+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:19 volumio2 go-librespot[32602]: time="2025-07-03T18:47:19+07:00" level=debug msg="completed challenge" Jul 03 18:47:19 volumio2 go-librespot[32602]: time="2025-07-03T18:47:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 03 18:47:19 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:19 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:19 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:19 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:22 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:22 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:22 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:22 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15353. Jul 03 18:47:22 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:22 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:22 volumio2 go-librespot[32613]: Librespot-go daemon starting... Jul 03 18:47:22 volumio2 go-librespot[32613]: time="2025-07-03T18:47:22+07:00" level=info msg="generated new device id: 9e1eb107f13a3d895655b6e673c2dfc227776c7d" Jul 03 18:47:22 volumio2 go-librespot[32613]: time="2025-07-03T18:47:22+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:23 volumio2 go-librespot[32613]: time="2025-07-03T18:47:23+07:00" level=debug msg="obtained new client token: AACQRlvnI2MLJSKmhn9kURSDy5Y0VAgtz1+Zv3uZgwoaGlb9gFlwADzw8AjUtT89JLh4yKI3ZwVKPdrsXCe2SzAF1k2WzINgqxG3QuDCvjsNUpaPT2JjsXY4z21qjMb7pOFZg0g8qb0w1cbZjzJAgH8PtUtp5vL3qr7BWQQe5SvFM5RpZnk5JhVEWFMAv7S32g1PdaWeTOuXlXA9CGWhO0Z6MPPZ9zVfOVrR1hTdm8QGBeqsqKBAQQ6RSw==" Jul 03 18:47:23 volumio2 go-librespot[32613]: time="2025-07-03T18:47: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 03 18:47:23 volumio2 go-librespot[32613]: time="2025-07-03T18:47:23+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:23 volumio2 go-librespot[32613]: time="2025-07-03T18:47:23+07:00" level=debug msg="completed challenge" Jul 03 18:47:23 volumio2 go-librespot[32613]: time="2025-07-03T18:47:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 03 18:47:23 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:23 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:25 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:25 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:26 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:26 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15354. Jul 03 18:47:26 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:26 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:26 volumio2 go-librespot[32620]: Librespot-go daemon starting... Jul 03 18:47:26 volumio2 go-librespot[32620]: time="2025-07-03T18:47:26+07:00" level=info msg="generated new device id: d46fd33535964cd823d53fd1e163a80a2496301d" Jul 03 18:47:26 volumio2 go-librespot[32620]: time="2025-07-03T18:47:26+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:27 volumio2 go-librespot[32620]: time="2025-07-03T18:47:27+07:00" level=debug msg="obtained new client token: AAARdZd/icqavY5o11JCj9olpyOJouENPbOk85vu7g7qqSJ2ITDu1Mw+y9qcI4OYdwl+FsmS0IAdyabw5n/EnvfA0oRJV+F7Y80qIcUIAG6bO92T2xQLrsO9r+RUEMoeUbSH3ppAo3O6QxYcWYY55vIHasoQTLXk4s7Vem7h1dezkKUMe68zfIkwqn9/L7+ySA7TLn6yQtUNYLi2F3nvejGpVNx9Eoi2YNyhwFo5eIM2oOlxP9Xe5OErpQ==" Jul 03 18:47:27 volumio2 go-librespot[32620]: time="2025-07-03T18:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 03 18:47:27 volumio2 go-librespot[32620]: time="2025-07-03T18:47:27+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:27 volumio2 go-librespot[32620]: time="2025-07-03T18:47:27+07:00" level=debug msg="completed challenge" Jul 03 18:47:27 volumio2 go-librespot[32620]: time="2025-07-03T18:47: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 03 18:47:27 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:27 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:28 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:28 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:30 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:30 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15355. Jul 03 18:47:30 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:30 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:30 volumio2 go-librespot[32641]: Librespot-go daemon starting... Jul 03 18:47:30 volumio2 go-librespot[32641]: time="2025-07-03T18:47:30+07:00" level=info msg="generated new device id: bedd55fda2f12e97c9f9191e55bc7a300e49bdff" Jul 03 18:47:30 volumio2 go-librespot[32641]: time="2025-07-03T18:47:30+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:31 volumio2 go-librespot[32641]: time="2025-07-03T18:47:31+07:00" level=debug msg="obtained new client token: AACEKhPfi7XF3Ul32qJQK2LnkXLCb1vX9sx82NcvikiuTfxzSWRu0A3+aoBV/RT1RmrNbX8hRoPLlbbYeDahP4y5yAfLHaPhq9UVAZsbwRSeaCxdE0h3eoJaV3ITBLaLfOQunFfs50p3VJXSpBlsT58T2DcUWaVTT5BcoYcVXxEe92E7ed5ACBjS3lakd2lHLA5CViFwBFC0rschBIb3NXi0rpvcXGzAiXhNYUOE9Lt1CaR7m5Ev5kXbmQ==" Jul 03 18:47:31 volumio2 go-librespot[32641]: time="2025-07-03T18:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:31 volumio2 go-librespot[32641]: time="2025-07-03T18:47:31+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:31 volumio2 go-librespot[32641]: time="2025-07-03T18:47:31+07:00" level=debug msg="completed challenge" Jul 03 18:47:31 volumio2 go-librespot[32641]: time="2025-07-03T18:47: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 03 18:47:31 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:31 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:31 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:31 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:34 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:34 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:34 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:34 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15356. Jul 03 18:47:34 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:34 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:34 volumio2 go-librespot[32693]: Librespot-go daemon starting... Jul 03 18:47:34 volumio2 go-librespot[32693]: time="2025-07-03T18:47:34+07:00" level=info msg="generated new device id: f4b650ade5d3697f74952aa3411712a216bf623b" Jul 03 18:47:34 volumio2 go-librespot[32693]: time="2025-07-03T18:47:34+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:35 volumio2 go-librespot[32693]: time="2025-07-03T18:47:35+07:00" level=debug msg="obtained new client token: AAC2XywnlrNYWwvtRSk7E5L4Dcj4yCCkp3wTNZvvQDhaASpqu31id2XJ2G/3/bOjiiri8zxj2CMjtn8iFOoUafvBlMUdjuOQwUs706nKmSKolwrdOzc+2lL7AOVNHZ/FQqnwKxU/fRTMFcXSV/CfVwlrli1K0HTYT1DZftWvDK2CDqGnp5S9dWt+cBUbgV0f9GYyd7/PhVmVfqlSIsWfqKAkpLRf33xObyddWZOQuwnxvZtVsBzF3Caukw==" Jul 03 18:47:35 volumio2 go-librespot[32693]: time="2025-07-03T18:47: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-gew4.spotify.com:80]" Jul 03 18:47:35 volumio2 go-librespot[32693]: time="2025-07-03T18:47:35+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:35 volumio2 go-librespot[32693]: time="2025-07-03T18:47:35+07:00" level=debug msg="completed challenge" Jul 03 18:47:35 volumio2 go-librespot[32693]: time="2025-07-03T18:47: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 03 18:47:35 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:35 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:37 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:37 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:38 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:38 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15357. Jul 03 18:47:38 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:38 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:38 volumio2 go-librespot[32715]: Librespot-go daemon starting... Jul 03 18:47:38 volumio2 go-librespot[32715]: time="2025-07-03T18:47:38+07:00" level=info msg="generated new device id: bdca7c9d54021ccbf5206e07f13e7d5a26da602d" Jul 03 18:47:38 volumio2 go-librespot[32715]: time="2025-07-03T18:47:38+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:39 volumio2 go-librespot[32715]: time="2025-07-03T18:47:39+07:00" level=debug msg="obtained new client token: AABV04j5uzczocObv9EbGhzQHjw3+KKUxP70T4/p5OZP17WWP9YIAu4Vc5cG87/CfBEtfx2A6EjQNBDaryUNKbuyTb5VlM1Ft/KnZCgpBYwc+8yp96Gjit/zuKb1BOzDZgcGI2xH3+lyHevqujowhEUU+hFFBU0Y64FB8E0ooK0TtRSweEMv7WrAMEWxkaUvMedJVZy1QLWkajxH9/Snr/jn3sU85+b1tsPv+mVHapzRs07VGwSBUrxMLw==" Jul 03 18:47:39 volumio2 go-librespot[32715]: time="2025-07-03T18:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:39 volumio2 go-librespot[32715]: time="2025-07-03T18:47:39+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:39 volumio2 go-librespot[32715]: time="2025-07-03T18:47:39+07:00" level=debug msg="completed challenge" Jul 03 18:47:39 volumio2 go-librespot[32715]: time="2025-07-03T18:47: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 03 18:47:39 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:39 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:40 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:40 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:42 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:42 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15358. Jul 03 18:47:42 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:42 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:42 volumio2 go-librespot[32726]: Librespot-go daemon starting... Jul 03 18:47:42 volumio2 go-librespot[32726]: time="2025-07-03T18:47:42+07:00" level=info msg="generated new device id: cd77afdfeea61a1e783bcf301fed99337234b30a" Jul 03 18:47:42 volumio2 go-librespot[32726]: time="2025-07-03T18:47:42+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:43 volumio2 go-librespot[32726]: time="2025-07-03T18:47:43+07:00" level=debug msg="obtained new client token: AAD26Jug/SRwoHBqzM1uszs3Km7ExS4+9lQX6uZ1YKcFbffLX2GBdaefAXOWpJfHvRjq+beZKanHDS/ZA0cE8HFl5vurxVWD++3R7uP4H9ZExpzOFgB7ALy2mM3i7leUfKMWsdg6hyz/oUsR159CMHuCFxHo7iE1IEcL0E4HmNRgfFdiZz/UP6st3DT0uCTpCiuIZwUbGq1ET1il7CHTbvH7tU8VUJBzLqUWMYscQqPxyz4pg7QOMCIQFQ==" Jul 03 18:47:43 volumio2 go-librespot[32726]: time="2025-07-03T18:47: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:43 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:43 volumio2 go-librespot[32726]: time="2025-07-03T18:47:43+07:00" level=debug msg="new websocket client" Jul 03 18:47:43 volumio2 volumio[1028]: info: Connection to go-librespot Websocket established Jul 03 18:47:44 volumio2 go-librespot[32726]: time="2025-07-03T18:47:44+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:44 volumio2 go-librespot[32726]: time="2025-07-03T18:47:44+07:00" level=debug msg="completed challenge" Jul 03 18:47:44 volumio2 go-librespot[32726]: time="2025-07-03T18:47:44+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 03 18:47:44 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:44 volumio2 volumio[1028]: info: Connection to go-librespot Websocket closed Jul 03 18:47:44 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:46 volumio2 volumio[1028]: info: Getting Spotify volume Jul 03 18:47:46 volumio2 volumio[1028]: (node:1028) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:46 volumio2 volumio[1028]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 03 18:47:46 volumio2 volumio[1028]: (node:1028) 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: 1886) Jul 03 18:47:46 volumio2 volumio[1028]: 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 03 18:47:46 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:46 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:47 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:47 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:47 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:47 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15359. Jul 03 18:47:47 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:47 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:47 volumio2 go-librespot[32735]: Librespot-go daemon starting... Jul 03 18:47:47 volumio2 go-librespot[32735]: time="2025-07-03T18:47:47+07:00" level=info msg="generated new device id: 58ec315ccb84f81a98f333c5ac700e69abc8d6f2" Jul 03 18:47:47 volumio2 go-librespot[32735]: time="2025-07-03T18:47:47+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:47 volumio2 go-librespot[32735]: time="2025-07-03T18:47:47+07:00" level=debug msg="obtained new client token: AADW2IU2ShoM6v1X0VropdSAI9ncHMqEiMJ7/3c8xvXqfnt2ZVaK1UQpnSjXONTdH9rUg2BSMRxlX9gPNBlBbEm0AA2NI61+A5GWhKXaj5eU+q7tGsKfpPRpedPpWP7gMfojl+lLdoS7yRqxBXTjRMxytMTiRKEfE2UTklH7IyU90d/foaUY4X58Ex0qEuGA2NAHJvEd8AQD+lXvZUFp4jTleBR1dxc9L4axKvHnGN3CoAGX8Wn0lxpAib2I" Jul 03 18:47:47 volumio2 go-librespot[32735]: time="2025-07-03T18:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:48 volumio2 go-librespot[32735]: time="2025-07-03T18:47:48+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:48 volumio2 go-librespot[32735]: time="2025-07-03T18:47:48+07:00" level=debug msg="completed challenge" Jul 03 18:47:48 volumio2 go-librespot[32735]: time="2025-07-03T18:47:48+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 03 18:47:48 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:48 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:47:50 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:50 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:47:50 volumio2 volumio[1028]: verbose: New Socket.io Connection to 192.168.1.41:3000 from 192.168.1.20 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:50 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 03 18:47:50 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 03 18:47:50 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:50 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:51 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:51 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15360. Jul 03 18:47:51 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:51 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:51 volumio2 go-librespot[32756]: Librespot-go daemon starting... Jul 03 18:47:51 volumio2 go-librespot[32756]: time="2025-07-03T18:47:51+07:00" level=info msg="generated new device id: a6009a7b2f8cb56e87960a54f140298801584ba7" Jul 03 18:47:51 volumio2 go-librespot[32756]: time="2025-07-03T18:47:51+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:51 volumio2 go-librespot[32756]: time="2025-07-03T18:47:51+07:00" level=debug msg="obtained new client token: AABBXmZq/+Xu/CeCLA6QUb8VoFMpEsFOJyvKH+pFkhe4+WB/nrKv1MInPESWf4k0fnk0G4GRqm4O0OCzKLtSdMlyAZy09V/PriZe7F8hmLkbhwrW/TsU7Hr0tUxbULmA8ivK+dzTsEqvj/IsQQyCD3lD49PW+rD+pr31wvrsSgDvNSgEnP4SciqEN4QS0hqqeI4cGeoUbBfVWgVs2KubLcHUTr5u7NLSsZYoKFG2Bz353yhtoMTW4p1Omttc" Jul 03 18:47:51 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:51 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:51 volumio2 go-librespot[32756]: time="2025-07-03T18:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 03 18:47:52 volumio2 go-librespot[32756]: time="2025-07-03T18:47:52+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:52 volumio2 sudo[32764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 03 18:47:52 volumio2 sudo[32764]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:47:52 volumio2 sudo[32764]: pam_unix(sudo:session): session closed for user root Jul 03 18:47:52 volumio2 sudo[32767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 03 18:47:52 volumio2 sudo[32767]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:47:52 volumio2 sudo[32767]: pam_unix(sudo:session): session closed for user root Jul 03 18:47:52 volumio2 volumio[1028]: verbose: New Socket.io Connection to 192.168.1.41 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 03 18:47:52 volumio2 go-librespot[32756]: time="2025-07-03T18:47:52+07:00" level=debug msg="completed challenge" Jul 03 18:47:52 volumio2 go-librespot[32756]: time="2025-07-03T18:47:52+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 03 18:47:52 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:52 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:52 volumio2 sudo[302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 03 18:47:52 volumio2 sudo[302]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:47:52 volumio2 sudo[302]: pam_unix(sudo:session): session closed for user root Jul 03 18:47:52 volumio2 sudo[305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 03 18:47:52 volumio2 sudo[305]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:47:52 volumio2 sudo[305]: pam_unix(sudo:session): session closed for user root Jul 03 18:47:52 volumio2 volumio[1028]: verbose: New Socket.io Connection to 192.168.1.41 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 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:52 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 03 18:47:52 volumio2 volumio[1028]: info: Listing playlists Jul 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 03 18:47:52 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 03 18:47:53 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:53 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetVisibleSources Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetQueue Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreStateMachine::getQueue Jul 03 18:47:54 volumio2 volumio[1028]: info: CorePlayQueue::getQueue Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:47:54 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:54 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:54 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:47:55 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:55 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15361. Jul 03 18:47:55 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:55 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:55 volumio2 go-librespot[307]: Librespot-go daemon starting... Jul 03 18:47:55 volumio2 go-librespot[307]: time="2025-07-03T18:47:55+07:00" level=info msg="generated new device id: 793b15f619f4951e3a61e346b1092ce9327f0716" Jul 03 18:47:55 volumio2 go-librespot[307]: time="2025-07-03T18:47:55+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:55 volumio2 go-librespot[307]: time="2025-07-03T18:47:55+07:00" level=debug msg="obtained new client token: AAAk+shOdye/Tge00oRLf5UotVoRCBhkQ2ZT73SmtwqaNBI8xIsFpxbTZeGlEgcNZ9rLbf7L/tUHYX54ZMSKgGtmvzWEtcAQUa/kZqZvF2DOsVJ3XRPzC9noXuzlqESqAoCUJYeNdebHKJMMZVNTjWw/SBHgJkJtwA0QYbuyQGfAaUvilAmLcPW5ft/mrT29faTx9gO5+cZ0MnNSbfFoypaF8ENj9m8CBSpw3BHk4EnnlTOEag/K/o5vYPPD" Jul 03 18:47:55 volumio2 go-librespot[307]: time="2025-07-03T18:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:47:56 volumio2 go-librespot[307]: time="2025-07-03T18:47:56+07:00" level=debug msg="completed keyexchange" Jul 03 18:47:56 volumio2 go-librespot[307]: time="2025-07-03T18:47:56+07:00" level=debug msg="completed challenge" Jul 03 18:47:56 volumio2 go-librespot[307]: time="2025-07-03T18:47:56+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 03 18:47:56 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:47:56 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:47:56 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:56 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 03 18:47:57 volumio2 volumio[1028]: info: Received Get System Info Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:47:57 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:47:57 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:47:57 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 03 18:47:59 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:47:59 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:47:59 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:47:59 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15362. Jul 03 18:47:59 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:47:59 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:47:59 volumio2 go-librespot[328]: Librespot-go daemon starting... Jul 03 18:47:59 volumio2 go-librespot[328]: time="2025-07-03T18:47:59+07:00" level=info msg="generated new device id: 4b1c2ba68ae68ac0f438f34b06fe0b8da431451c" Jul 03 18:47:59 volumio2 go-librespot[328]: time="2025-07-03T18:47:59+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:47:59 volumio2 go-librespot[328]: time="2025-07-03T18:47:59+07:00" level=debug msg="obtained new client token: AACUMA5OSAnU/ZMv2OAXuE2lSBTNxH1PcFy6/R+PB03lhOnJtZ/rgR7WIiW4UtG4JYMuexXgkaU6I0MLMLSEf9sCQls4oav2TLpyLCrFwR/JPB2DkzrZdS55VYak/fe4dCNXDworA6ER56MHW/INMNVZIB52C+/ojREefrVjHSbyIJpEs1NA/D1P0hs0/cwkiO/qKYtOBL7vTjfZDChC7bU+XdNPEELxTtEnCoQAJzSbsLQrA3T/Kax1z4Tb" Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: info: Retrieving Cloud Streaming UI Jul 03 18:47:59 volumio2 volumio[1028]: info: Getting Tidal Cloud Configuration Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: info: Getting Qobuz Cloud Configuration Jul 03 18:47:59 volumio2 volumio[1028]: info: Asking plugin for UI Config Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: info: Getting Spotify Cloud Configuration Jul 03 18:47:59 volumio2 volumio[1028]: info: Asking plugin for UI Config Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: info: Saving Spotify Acccount Jul 03 18:47:59 volumio2 volumio[1028]: info: Got Tidal Cloud Configuration Jul 03 18:47:59 volumio2 volumio[1028]: info: Got it Jul 03 18:47:59 volumio2 volumio[1028]: info: Got it Jul 03 18:47:59 volumio2 volumio[1028]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:47:59 volumio2 volumio[1028]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:47:59 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:47:59 volumio2 go-librespot[328]: time="2025-07-03T18:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 03 18:48:00 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 03 18:48:00 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 03 18:48:00 volumio2 go-librespot[328]: time="2025-07-03T18:48:00+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:00 volumio2 go-librespot[328]: time="2025-07-03T18:48:00+07:00" level=debug msg="completed challenge" Jul 03 18:48:00 volumio2 go-librespot[328]: time="2025-07-03T18:48: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 03 18:48:00 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:00 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:01 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 03 18:48:01 volumio2 volumio[1028]: info: Received Get System Info Jul 03 18:48:01 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:48:01 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:48:01 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:48:01 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:48:01 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:01 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 03 18:48:02 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 18:48:02 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:02 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:03 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:03 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15363. Jul 03 18:48:03 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:03 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:03 volumio2 go-librespot[343]: Librespot-go daemon starting... Jul 03 18:48:03 volumio2 go-librespot[343]: time="2025-07-03T18:48:03+07:00" level=info msg="generated new device id: 900750e1d919b5efad478f4c7a443544bc8fbc49" Jul 03 18:48:03 volumio2 go-librespot[343]: time="2025-07-03T18:48:03+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:03 volumio2 go-librespot[343]: time="2025-07-03T18:48:03+07:00" level=debug msg="obtained new client token: AACQit/fO823ZvZqT95oNgX0Qpz6u2m+QyHwLniOdKGW8yDQl8O3y17pQ10Zb261q+FPouAqgnPrqOiS/ma8z8dLi7HCBwFoVxxxE44yk3PNI/CXIYxMGEweikSsnZRu68wXAWJLzefpnLohiebvuh6MT5QRs5yQtTYdTpy2r1mBFKYTx1OBeajPSu/iDttnH1B5hhejmdZsJ86jPUQazbr/4AN+tiKNIfxIfyI6XsOGrOYX3ypgijsrfk9R" Jul 03 18:48:03 volumio2 go-librespot[343]: time="2025-07-03T18:48:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:48:04 volumio2 go-librespot[343]: time="2025-07-03T18:48:04+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:04 volumio2 go-librespot[343]: time="2025-07-03T18:48:04+07:00" level=debug msg="completed challenge" Jul 03 18:48:04 volumio2 go-librespot[343]: time="2025-07-03T18:48:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 03 18:48:04 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:04 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:05 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:05 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:07 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:07 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15364. Jul 03 18:48:07 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:07 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:07 volumio2 go-librespot[352]: Librespot-go daemon starting... Jul 03 18:48:07 volumio2 go-librespot[352]: time="2025-07-03T18:48:07+07:00" level=info msg="generated new device id: 64abfaedd1c091d81030681e15a5131a3dac1bf3" Jul 03 18:48:07 volumio2 go-librespot[352]: time="2025-07-03T18:48:07+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:07 volumio2 go-librespot[352]: time="2025-07-03T18:48:07+07:00" level=debug msg="obtained new client token: AAADiz1Z6ygxUbGxbSOvt6vMNEzMHvFY+zukX1WrYWd9iA2tNtq6TxKHCt1KItPRpg61ZdJ+GfXCTB79jFyPC3Nosxla01LDBmruzzJxFFJsL33vqM4P8aOHN+2tEq1Vt5pOhfWFx/VlSzmg9AQVVvlCj3WXTroifpY6x1mGiFHRBxyBm84ki2Mip3wyEOEM4PN7ek1Aveu1EQ55TZ5t0lA0PRla1luuCZTvg8BNXfX67veRurGOb/5jzYA4" Jul 03 18:48:07 volumio2 go-librespot[352]: time="2025-07-03T18:48: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]" Jul 03 18:48:08 volumio2 go-librespot[352]: time="2025-07-03T18:48:08+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:08 volumio2 go-librespot[352]: time="2025-07-03T18:48:08+07:00" level=debug msg="completed challenge" Jul 03 18:48:08 volumio2 go-librespot[352]: time="2025-07-03T18:48: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 03 18:48:08 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:08 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:08 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:08 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:09 volumio2 volumio[1028]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jul 03 18:48:09 volumio2 volumio[1028]: info: Preparing to save Alsa Options, stopping services first Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:48:09 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPause Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreStateMachine::pause Jul 03 18:48:09 volumio2 volumio[1028]: info: Saving Audio Output to: {"output_device":{"value":"2","label":"USB Audio DAC"}} Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 18:48:09 volumio2 volumio[1028]: info: Setting mixer PCM for card USB Audio DAC Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 03 18:48:09 volumio2 volumio[1028]: info: Updating Volume Controller Parameters: Device: 2 Name: USB Audio DAC Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 03 18:48:09 volumio2 volumio[1028]: info: Disabling external Volume Control Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:09 volumio2 volumio[1028]: info: Preparing to generate the ALSA configuration file Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 18:48:09 volumio2 volumio[1028]: info: VolumeController:: Volume=46 Mute =false Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreStateMachine::pushState Jul 03 18:48:09 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPushState Jul 03 18:48:09 volumio2 volumio[1028]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Jul 03 18:48:09 volumio2 volumio[1028]: SPOTIFY: SPOTIFY VOLUME undefined Jul 03 18:48:09 volumio2 volumio[1028]: SPOTIFY: VOLUMIO VOLUME 46 Jul 03 18:48:09 volumio2 volumio[1028]: info: Aligning Spotify Volume to Volumio Volume Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:48:09 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:09 volumio2 volumio[1028]: info: Setting Spotify Volume from Volumio: 46 Jul 03 18:48:09 volumio2 volumio[1028]: info: Asound.conf file written Jul 03 18:48:09 volumio2 sudo[390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jul 03 18:48:09 volumio2 sudo[390]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 sudo[390]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: No state is present for card DAC Jul 03 18:48:09 volumio2 volumio[1028]: Found hardware: "USB-Audio" "USB Mixer" "USB08bb:2704" "" "" Jul 03 18:48:09 volumio2 volumio[1028]: Hardware is initialized using a generic method Jul 03 18:48:09 volumio2 volumio[1028]: No state is present for card DAC Jul 03 18:48:09 volumio2 volumio[1028]: info: Output device has changed, restarting MPD Jul 03 18:48:09 volumio2 sudo[397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 18:48:09 volumio2 sudo[397]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 volumio[1028]: info: Output device has changed, restarting Shairport Sync Jul 03 18:48:09 volumio2 sudo[397]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:09 volumio2 sudo[400]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 18:48:09 volumio2 sudo[400]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 systemd[1]: Stopping Music Player Daemon... Jul 03 18:48:09 volumio2 volumio[1028]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 18:48:09 volumio2 volumio[1028]: info: Output device has changed, restarting MPD Jul 03 18:48:09 volumio2 systemd[1]: mpd.service: Succeeded. Jul 03 18:48:09 volumio2 systemd[1]: Stopped Music Player Daemon. Jul 03 18:48:09 volumio2 sudo[407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 18:48:09 volumio2 sudo[407]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 systemd[1]: Starting Music Player Daemon... Jul 03 18:48:09 volumio2 volumio[1028]: info: Output device has changed, restarting Shairport Sync Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 sudo[407]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:09 volumio2 sudo[410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 18:48:09 volumio2 sudo[410]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jul 03 18:48:09 volumio2 systemd[1]: mpd.service: Succeeded. Jul 03 18:48:09 volumio2 systemd[1]: Stopped Music Player Daemon. Jul 03 18:48:09 volumio2 volumio[1028]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 18:48:09 volumio2 systemd[1]: Starting Music Player Daemon... Jul 03 18:48:09 volumio2 volumio[1028]: info: MPD Permissions set Jul 03 18:48:09 volumio2 volumio[1028]: info: MPD Permissions set Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 sudo[417]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 18:48:09 volumio2 sudo[417]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 sudo[417]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 03 18:48:09 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:09 volumio2 volumio[1028]: info: Starting Shairport Sync Jul 03 18:48:09 volumio2 volumio[1028]: info: Starting Shairport Sync Jul 03 18:48:09 volumio2 sudo[433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 18:48:09 volumio2 sudo[433]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 18:48:09 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jul 03 18:48:09 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 18:48:09 volumio2 sudo[437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 18:48:09 volumio2 sudo[437]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:09 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 18:48:09 volumio2 sudo[433]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: info: Shairport-Sync Started Jul 03 18:48:09 volumio2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 18:48:09 volumio2 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jul 03 18:48:09 volumio2 systemd[1]: shairport-sync.service: Succeeded. Jul 03 18:48:09 volumio2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 18:48:09 volumio2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 18:48:09 volumio2 sudo[437]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:09 volumio2 volumio[1028]: info: Shairport-Sync Started Jul 03 18:48:09 volumio2 mpd[425]: Jul 03 18:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 18:48:09 volumio2 systemd[1]: Started Music Player Daemon. Jul 03 18:48:09 volumio2 sudo[400]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:10 volumio2 sudo[410]: pam_unix(sudo:session): session closed for user root Jul 03 18:48:10 volumio2 volumio[1028]: error: MPD error: The expression evaluated to a falsy value: Jul 03 18:48:10 volumio2 volumio[1028]: assert.ok(self.idling) Jul 03 18:48:10 volumio2 volumio[1028]: error: The expression evaluated to a falsy value: Jul 03 18:48:10 volumio2 volumio[1028]: assert.ok(self.idling) Jul 03 18:48:10 volumio2 volumio[1028]: error: updateQueue error: null Jul 03 18:48:10 volumio2 volumio[1028]: SPOTIFY: SETTING SPOTIFY VOLUME 46 Jul 03 18:48:10 volumio2 volumio[1028]: info: Sending Spotify command with payload to local API: /player/volume Jul 03 18:48:10 volumio2 volumio[1028]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:11 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:11 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:11 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:11 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15365. Jul 03 18:48:11 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:11 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:11 volumio2 go-librespot[444]: Librespot-go daemon starting... Jul 03 18:48:11 volumio2 go-librespot[444]: time="2025-07-03T18:48:11+07:00" level=info msg="generated new device id: 1f2c5298efdba435f2d46e647290d85106436bb8" Jul 03 18:48:11 volumio2 go-librespot[444]: time="2025-07-03T18:48:11+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:11 volumio2 go-librespot[444]: time="2025-07-03T18:48:11+07:00" level=debug msg="obtained new client token: AADnQqCS3OtGhTz3AMs+eNAYjoQ3rYD3dZB7hvQkBpB0OOjUkViHFgYjGY4FjQbIYOO6996r8PaN6y4eBiy4DMNlvpmOEuZ4/aShf35Z/J+4ZAf6b9scAgTkQgUuCjlNiqvks7+z46+zu8d22hdwnsUxdX+eCIogh/c97sA+pwtK/TlhXETES8hvdja12Rtf9/jlvhn0AmeZvituQwj7fYWowbNqF1pRbdZ4KZ/q5Tw0FJWF+H2MD81SqDxr" Jul 03 18:48:11 volumio2 go-librespot[444]: time="2025-07-03T18:48:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:48:12 volumio2 go-librespot[444]: time="2025-07-03T18:48:12+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:12 volumio2 go-librespot[444]: time="2025-07-03T18:48:12+07:00" level=debug msg="completed challenge" Jul 03 18:48:12 volumio2 go-librespot[444]: time="2025-07-03T18:48: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 03 18:48:12 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:12 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreStateMachine::getcurrentVolume Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 18:48:13 volumio2 volumio[1028]: info: VolumeController:: Volume=46 Mute =false Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreStateMachine::pushState Jul 03 18:48:13 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPushState Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreStateMachine::updateTrackBlock Jul 03 18:48:13 volumio2 volumio[1028]: info: CorePlayQueue::getTrackBlock Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 18:48:13 volumio2 volumio[1028]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Jul 03 18:48:13 volumio2 volumio[1028]: info: VolumeController:: Volume=46 Mute =false Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreStateMachine::pushState Jul 03 18:48:13 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:13 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPushState Jul 03 18:48:13 volumio2 volumio[1028]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Jul 03 18:48:14 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 18:48:14 volumio2 volumio[1028]: info: VolumeController:: Setting startup Volume 100 Jul 03 18:48:14 volumio2 volumio[1028]: info: VolumeController::SetAlsaVolume100 Jul 03 18:48:14 volumio2 volumio[1028]: info: CoreStateMachine::pushState Jul 03 18:48:14 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:14 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 18:48:14 volumio2 volumio[1028]: info: CoreCommandRouter::volumioPushState Jul 03 18:48:14 volumio2 volumio[1028]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 03 18:48:14 volumio2 volumio[1028]: SPOTIFY: SPOTIFY VOLUME 46 Jul 03 18:48:14 volumio2 volumio[1028]: SPOTIFY: VOLUMIO VOLUME 100 Jul 03 18:48:14 volumio2 volumio[1028]: SPOTIFY: DELTA VOLUME ENOUGH: true Jul 03 18:48:14 volumio2 volumio[1028]: info: Setting Spotify Volume from Volumio: 100 Jul 03 18:48:14 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:14 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 03 18:48:15 volumio2 volumio[1028]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 03 18:48:15 volumio2 volumio[1028]: info: Received Get System Version Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 03 18:48:15 volumio2 volumio[1028]: info: Received Get System Info Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:48:15 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:48:15 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:15 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:48:15 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:15 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15366. Jul 03 18:48:15 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:15 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:15 volumio2 go-librespot[459]: Librespot-go daemon starting... Jul 03 18:48:15 volumio2 go-librespot[459]: time="2025-07-03T18:48:15+07:00" level=info msg="generated new device id: 563571c55d334003248615fd25023894b2036d8b" Jul 03 18:48:15 volumio2 go-librespot[459]: time="2025-07-03T18:48:15+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:15 volumio2 volumio[1028]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jul 03 18:48:15 volumio2 volumio[1028]: info: Sending Spotify command with payload to local API: /player/volume Jul 03 18:48:15 volumio2 go-librespot[459]: time="2025-07-03T18:48:15+07:00" level=debug msg="obtained new client token: AAAudkf3iS+/3x1fYxl8eog17rmS6p1JxeGoEoTwT5YA1eLL5IE1U5j4cGsIpLNxR2JLpv7ft69ybHOwvcX2wWqK4SkNej1XtZBbpTnzKyWJ17uq7jD8FJ7m6G19A7cpDTTKOCN3awyqMLWLs32zBX+Ry/t1S84+AuFemcrBTL3iSpGISHLnrZXsgU4LRgTIBaPdBK561JeTBFE0GOeA9V9N5QtMkd2rfl+MZ1z2J7yOHzwRom15hzu+TCPf" Jul 03 18:48:15 volumio2 go-librespot[459]: time="2025-07-03T18:48:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:48:16 volumio2 go-librespot[459]: time="2025-07-03T18:48:16+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:16 volumio2 go-librespot[459]: time="2025-07-03T18:48:16+07:00" level=debug msg="completed challenge" Jul 03 18:48:16 volumio2 go-librespot[459]: time="2025-07-03T18:48: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 03 18:48:16 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:16 volumio2 volumio[1028]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jul 03 18:48:16 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:17 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:17 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:19 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 03 18:48:19 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 03 18:48:19 volumio2 volumio[1028]: info: Discovery: Getting this device information Jul 03 18:48:19 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetState Jul 03 18:48:19 volumio2 volumio[1028]: info: CorePlayQueue::getTrack 0 Jul 03 18:48:19 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 18:48:19 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:19 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15367. Jul 03 18:48:19 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:19 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:19 volumio2 go-librespot[481]: Librespot-go daemon starting... Jul 03 18:48:19 volumio2 go-librespot[481]: time="2025-07-03T18:48:19+07:00" level=info msg="generated new device id: 92b01f3630ce2c02d233e72eafe26f9111b974e8" Jul 03 18:48:19 volumio2 go-librespot[481]: time="2025-07-03T18:48:19+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:19 volumio2 go-librespot[481]: time="2025-07-03T18:48:19+07:00" level=debug msg="obtained new client token: AADOvEOLBxaBwnsYFg2VAMBHHOV9FEmW+7xCygBla3OxKTlOYmqz2MDUOk6HDXE8wvyvKAE+g0BTyBCkNbg3ILejAOI54ghCudxrQWEZeOeCnnmlDVbY1mLHobjQvG89lO7WQj4rbPy1uq8T2Utv2FfwkA9AneFEPKgsYJiwxuD7OyrK4i11gdJcdwtbytxXvzv3WcOfHO1LOBMeFAvDoeUOdmdZuXJ/buj7/WYb2Fskn4Z76hIMkhd6aUTv" Jul 03 18:48:19 volumio2 go-librespot[481]: time="2025-07-03T18:48: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 03 18:48:20 volumio2 go-librespot[481]: time="2025-07-03T18:48:20+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: info: Retrieving Cloud Streaming UI Jul 03 18:48:20 volumio2 volumio[1028]: info: Getting Tidal Cloud Configuration Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: info: Getting Qobuz Cloud Configuration Jul 03 18:48:20 volumio2 volumio[1028]: info: Asking plugin for UI Config Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: info: Getting Spotify Cloud Configuration Jul 03 18:48:20 volumio2 volumio[1028]: info: Asking plugin for UI Config Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: info: Saving Spotify Acccount Jul 03 18:48:20 volumio2 volumio[1028]: info: Got Tidal Cloud Configuration Jul 03 18:48:20 volumio2 volumio[1028]: info: Got it Jul 03 18:48:20 volumio2 volumio[1028]: info: Got it Jul 03 18:48:20 volumio2 volumio[1028]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 18:48:20 volumio2 volumio[1028]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::volumioGetBrowseSources Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 03 18:48:20 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 03 18:48:20 volumio2 go-librespot[481]: time="2025-07-03T18:48:20+07:00" level=debug msg="completed challenge" Jul 03 18:48:20 volumio2 go-librespot[481]: time="2025-07-03T18:48: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 03 18:48:20 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:20 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:20 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:20 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:22 volumio2 volumio[1028]: info: Disabling MyMusic plugin upnp Jul 03 18:48:22 volumio2 sudo[493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jul 03 18:48:22 volumio2 sudo[493]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 18:48:22 volumio2 systemd[1]: Stopping UPnP Renderer front-end to MPD... Jul 03 18:48:22 volumio2 volumio[1028]: error: Upnp client error: Error: This socket has been ended by the other party Jul 03 18:48:23 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:23 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:23 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:23 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15368. Jul 03 18:48:23 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:23 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:23 volumio2 go-librespot[495]: Librespot-go daemon starting... Jul 03 18:48:23 volumio2 go-librespot[495]: time="2025-07-03T18:48:23+07:00" level=info msg="generated new device id: c4c5bb98dbc1c01c359ad9aaa6086b578eaedb15" Jul 03 18:48:23 volumio2 go-librespot[495]: time="2025-07-03T18:48:23+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:23 volumio2 go-librespot[495]: time="2025-07-03T18:48:23+07:00" level=debug msg="obtained new client token: AACPPgjriOv259gP466DtTc/eS1dQ3OOn/fhGhc/AjQxrFY3iK9/HVhYca8CCTYAx3CCumIPT6bhgYo9Qj3URywb8Qapjch8Pv4dxohCvaZWC9kHeJoHR+L3kJ0CCW3tml361C3UqhsCMLSZfCw9QRx4WeIYUnZ0Ltch5XFHjWNh+p86dbDPqa2RClM8S0M2lLatcKuK4o/x6mf2SpDhTKv1Ph9/3T7VdbL90tc58HyQJTaELA3UWjLGNpXo" Jul 03 18:48:24 volumio2 go-librespot[495]: time="2025-07-03T18:48: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]" Jul 03 18:48:24 volumio2 go-librespot[495]: time="2025-07-03T18:48:24+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:24 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 03 18:48:24 volumio2 go-librespot[495]: time="2025-07-03T18:48:24+07:00" level=debug msg="completed challenge" Jul 03 18:48:24 volumio2 go-librespot[495]: time="2025-07-03T18:48:24+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 03 18:48:24 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 03 18:48:24 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 03 18:48:26 volumio2 volumio[1028]: info: Initializing connection to go-librespot Websocket Jul 03 18:48:26 volumio2 volumio[1028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 03 18:48:27 volumio2 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 03 18:48:27 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15369. Jul 03 18:48:27 volumio2 systemd[1]: Stopped go-librespot Daemon. Jul 03 18:48:27 volumio2 systemd[1]: Started go-librespot Daemon. Jul 03 18:48:27 volumio2 go-librespot[503]: Librespot-go daemon starting... Jul 03 18:48:27 volumio2 go-librespot[503]: time="2025-07-03T18:48:27+07:00" level=info msg="generated new device id: 50bd45326a64dfb22d6e02b8d92cb0c3e21e95fa" Jul 03 18:48:27 volumio2 go-librespot[503]: time="2025-07-03T18:48:27+07:00" level=debug msg="stored credentials found for tp20pocsknlcll7n6w5hgfvb0" Jul 03 18:48:27 volumio2 go-librespot[503]: time="2025-07-03T18:48:27+07:00" level=debug msg="obtained new client token: AAAanotlMHnfgWBJHakUq8zQQgSBiEi5UVQEM7rzm+Gz85OmxFfRbCRpQ/9ozqRGfLCMn2ywfv7N8WsF26LgK8zDpnIFwK7JDsl+q+fPOP0n1iDqORX6eBnQRC4LC9ZclJ8G3hnWLV7YrJoOVp+Hz4n8q7PhnxxYQH/r35V4mTJXAsAtPfE5XXMZPrtDe6XooSNrVMiXDyTPPDzRXZw0XdFMIffWU6lxMaLv1Bw3W2y36RssI8rGycuUWEPm" Jul 03 18:48:27 volumio2 volumio[1028]: info: Enabling MyMusic plugin upnp Jul 03 18:48:27 volumio2 volumio[1028]: info: Enabling plugin upnp Jul 03 18:48:27 volumio2 volumio[1028]: info: Loading plugin "upnp"... Jul 03 18:48:27 volumio2 volumio[1028]: info: [1751543307918] Starting Upmpd Daemon Jul 03 18:48:27 volumio2 volumio[1028]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 03 18:48:27 volumio2 volumio[1028]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 18:48:27 volumio2 volumio[1028]: Error: listen EADDRINUSE: address already in use :::6599 Jul 03 18:48:27 volumio2 volumio[1028]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jul 03 18:48:27 volumio2 volumio[1028]: at listenInCluster (net.js:1379:12) Jul 03 18:48:27 volumio2 volumio[1028]: at Server.listen (net.js:1465:7) Jul 03 18:48:27 volumio2 volumio[1028]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jul 03 18:48:27 volumio2 volumio[1028]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jul 03 18:48:27 volumio2 volumio[1028]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jul 03 18:48:27 volumio2 volumio[1028]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 03 18:48:27 volumio2 volumio[1028]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jul 03 18:48:27 volumio2 volumio[1028]: code: 'EADDRINUSE', Jul 03 18:48:27 volumio2 volumio[1028]: errno: -98, Jul 03 18:48:27 volumio2 volumio[1028]: syscall: 'listen', Jul 03 18:48:27 volumio2 volumio[1028]: address: '::', Jul 03 18:48:27 volumio2 volumio[1028]: port: 6599 Jul 03 18:48:27 volumio2 volumio[1028]: } Jul 03 18:48:27 volumio2 volumio[1028]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 18:48:27 volumio2 go-librespot[503]: time="2025-07-03T18:48: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 03 18:48:28 volumio2 go-librespot[503]: time="2025-07-03T18:48:28+07:00" level=debug msg="completed keyexchange" Jul 03 18:48:28 volumio2 sudo[521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-03 18:47 Jul 03 18:48:28 volumio2 sudo[521]: 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"