-- Logs begin at Sun 2025-12-28 13:01:16 KST, end at Sun 2025-12-28 15:29:01 KST. -- Dec 28 15:28:00 volumio-jason go-librespot[16403]: time="2025-12-28T15:28:00+09: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]" Dec 28 15:28:00 volumio-jason go-librespot[16403]: time="2025-12-28T15:28:00+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:01 volumio-jason go-librespot[16403]: time="2025-12-28T15:28:01+09:00" level=debug msg="completed challenge" Dec 28 15:28:01 volumio-jason go-librespot[16403]: time="2025-12-28T15:28:01+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:01 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:01 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:01 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:01 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:03 volumio-jason volumio[862]: info: MyVolumio login type: Token Dec 28 15:28:04 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:04 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11119. Dec 28 15:28:04 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:04 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:04 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:04 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:04 volumio-jason go-librespot[16412]: Librespot-go daemon starting... Dec 28 15:28:04 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:04+09:00" level=info msg="generated new device id: 4f2ea7587b7ede77009c5597b66da165d27d5255" Dec 28 15:28:04 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:04+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:05 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:05+09:00" level=debug msg="obtained new client token: AAAoPA9vj7JZ+Q+7AIJkakbmwQsNZQI+SHuE11Cs9pPGu3WNBMmTDzO8gnnlSJp/qaHnYNIbgHRKpMTkQ5Z8f+Ed3auNkJ4ufmWKfoTCnJfUaVM8LYYgw9LrPbrU15j7IDmt6jVw/RVqK6uTgNuE4ZLJaPK7E1B8YIR9ocDPjAOUVP+nnGt0TJLfOhucBeGLjBqkGY3aicFTVOKdLNajhOaU2pUJHhmUAxGP+Ja4f2xRBNhqypC9AX0A5Nro" Dec 28 15:28:07 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:07+09: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]" Dec 28 15:28:07 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:07+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:07 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:07 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:07+09:00" level=debug msg="new websocket client" Dec 28 15:28:07 volumio-jason volumio[862]: info: Connection to go-librespot Websocket established Dec 28 15:28:07 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:07+09:00" level=debug msg="completed challenge" Dec 28 15:28:07 volumio-jason go-librespot[16412]: time="2025-12-28T15:28:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:07 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:07 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:07 volumio-jason volumio[862]: info: Connection to go-librespot Websocket closed Dec 28 15:28:10 volumio-jason volumio[862]: info: Getting Spotify volume Dec 28 15:28:10 volumio-jason volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:10 volumio-jason volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 15:28:10 volumio-jason volumio[862]: (node:862) 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: 6632) Dec 28 15:28:10 volumio-jason volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Dec 28 15:28:10 volumio-jason volumio[862]: info: CoreCommandRouter::volumioGetState Dec 28 15:28:10 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:10 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:10 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:10 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:10 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11120. Dec 28 15:28:10 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:10 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:10 volumio-jason go-librespot[16420]: Librespot-go daemon starting... Dec 28 15:28:10 volumio-jason go-librespot[16420]: time="2025-12-28T15:28:10+09:00" level=info msg="generated new device id: 4cb14bbd80646c9001710a368e75dc818f79f61c" Dec 28 15:28:10 volumio-jason go-librespot[16420]: time="2025-12-28T15:28:10+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:11 volumio-jason go-librespot[16420]: time="2025-12-28T15:28:11+09:00" level=debug msg="obtained new client token: AABeqEf+dlM+6585c1SBFmJNYsIBPFzGNMO9Jo2P0dSOe2TLDcHcNZluJL+H3AVWTw/kyAw3V6VZg4HOXelCg5JMFAXC0FiaK1wFB3MrVRWKZssUnH33mqsZiqVM8zFYckRffiqw1sJPpYzFcsAmh7AIeh1frclys2/l3p6Jr19cvoaz9/E1BCVlF8kwXTUiUsFQySQb6UBD5iH6pF6mzQGUZF88YN7JAO5konLjwmb0LY8JOrQvmmeGLoZvs+M=" Dec 28 15:28:12 volumio-jason go-librespot[16420]: time="2025-12-28T15:28:12+09: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]" Dec 28 15:28:12 volumio-jason go-librespot[16420]: time="2025-12-28T15:28:12+09: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" Dec 28 15:28:12 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:12 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:13 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:13 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:15 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:15 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11121. Dec 28 15:28:15 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:15 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:15 volumio-jason go-librespot[16429]: Librespot-go daemon starting... Dec 28 15:28:15 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:15+09:00" level=info msg="generated new device id: 44e180c77bf767a9f53525cac2095e3baaf09687" Dec 28 15:28:15 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:15+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:16 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:16 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:16+09:00" level=debug msg="new websocket client" Dec 28 15:28:16 volumio-jason volumio[862]: info: Connection to go-librespot Websocket established Dec 28 15:28:16 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:16+09:00" level=debug msg="obtained new client token: AABEqIiOCHcXBr6wb60DOSzyW/2tSCEbJYqa3EnnRYpvCvTiDe6xCAQ0SroXYQTnImserThs3wA/brzabZF/NRg3pOoiZr2j71oS4a0rT+1ECa8uSA8cG3bnKQvitQIu/Vm0InLAqX0TeC4Y579QDesMLdl74/gxIKLToFVM/22sGIIJau7NVcGLNHEHFCweeAuD/IQbXSsGNoTndjGeKt0oNal1zqor8LgzLddNtyO0zt0GZd3f1mKtTTQgayM=" Dec 28 15:28:17 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:17+09: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]" Dec 28 15:28:18 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:18+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:18 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:18+09:00" level=debug msg="completed challenge" Dec 28 15:28:18 volumio-jason go-librespot[16429]: time="2025-12-28T15:28:18+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:18 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:18 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:18 volumio-jason volumio[862]: info: Connection to go-librespot Websocket closed Dec 28 15:28:19 volumio-jason volumio[862]: info: Getting Spotify volume Dec 28 15:28:19 volumio-jason volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:19 volumio-jason volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 15:28:19 volumio-jason volumio[862]: (node:862) 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: 6633) Dec 28 15:28:19 volumio-jason volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Dec 28 15:28:19 volumio-jason volumio[862]: info: CoreCommandRouter::volumioGetState Dec 28 15:28:19 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:21 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:21 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:21 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:21 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11122. Dec 28 15:28:21 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:21 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:21 volumio-jason go-librespot[16437]: Librespot-go daemon starting... Dec 28 15:28:21 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:21+09:00" level=info msg="generated new device id: ec5652601d11caadce2d652fe8347d83503c2afe" Dec 28 15:28:21 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:21+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:22 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:22+09:00" level=debug msg="obtained new client token: AACew3Bqzdoa/XJa+VTcZMCTlk2qVO89tuEM27NFjfQxndnpFPIjjBhbrrcNO2QZjtZAIcO6G5owbWl+siRPouQ98+pFkmgxFeE37lufc9qS0wO9QabUNxPKpL4JxRigM7Mt/XC8FgZa+lpvZX3QGej9NLzrcf/NcdmuiYinGc4aR0w5qfjo2OR/exG2y2fv+B8XW5iShXM7G7EZAQx/pofKyP6aGB853fZfNcxIKHU886podufIIFP0mDZHgMk=" Dec 28 15:28:23 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:23+09: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]" Dec 28 15:28:24 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:24+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:24 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:24 volumio-jason volumio[862]: info: Connection to go-librespot Websocket established Dec 28 15:28:24 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:24+09:00" level=debug msg="new websocket client" Dec 28 15:28:24 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:24+09:00" level=debug msg="completed challenge" Dec 28 15:28:24 volumio-jason go-librespot[16437]: time="2025-12-28T15:28:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:24 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:24 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:24 volumio-jason volumio[862]: info: Connection to go-librespot Websocket closed Dec 28 15:28:27 volumio-jason volumio[862]: info: Getting Spotify volume Dec 28 15:28:27 volumio-jason volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:27 volumio-jason volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 15:28:27 volumio-jason volumio[862]: (node:862) 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: 6634) Dec 28 15:28:27 volumio-jason volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Dec 28 15:28:27 volumio-jason volumio[862]: info: CoreCommandRouter::volumioGetState Dec 28 15:28:27 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:27 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:27 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:28 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:28 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11123. Dec 28 15:28:28 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:28 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:28 volumio-jason go-librespot[16446]: Librespot-go daemon starting... Dec 28 15:28:28 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:28+09:00" level=info msg="generated new device id: 222948cbc95287bb8e538e94ca07f234ffbe619b" Dec 28 15:28:28 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:28+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:30 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:30+09:00" level=debug msg="obtained new client token: AABy2ys9HMp0SwBpq9LK1w+JVcpc/4QZlOdjSdBkUVfNtcz2+hYZgMEfyvKavNWIHzFZSUQQdQnZc3iWcjMux/EgcADpWKYn0sWu5YG9iSVVCGuZRLVR3ySzgBqKyNr2PSIr1E2fPXK1gmmwEC6eQSnrdk44uCWbdjHwz8aNcu6mYLWczq+kqMjnOxnNJvnAmsOAvfZENn7DppvRc45uwq8lCgrblvrhkZsbM4VQTI6qlhJh8jFj/xMt6B9MprA=" Dec 28 15:28:30 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:30 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:30+09:00" level=debug msg="new websocket client" Dec 28 15:28:30 volumio-jason volumio[862]: info: Connection to go-librespot Websocket established Dec 28 15:28:31 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:31+09: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]" Dec 28 15:28:31 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:31+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:32 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:32+09:00" level=debug msg="completed challenge" Dec 28 15:28:32 volumio-jason go-librespot[16446]: time="2025-12-28T15:28:32+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:32 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:32 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:32 volumio-jason volumio[862]: info: Connection to go-librespot Websocket closed Dec 28 15:28:33 volumio-jason volumio[862]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Dec 28 15:28:33 volumio-jason volumio[862]: info: Retrying Login Due to Network Error Dec 28 15:28:33 volumio-jason volumio[862]: info: Getting Spotify volume Dec 28 15:28:33 volumio-jason volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:33 volumio-jason volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 15:28:33 volumio-jason volumio[862]: (node:862) 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: 6635) Dec 28 15:28:33 volumio-jason volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Dec 28 15:28:33 volumio-jason volumio[862]: info: CoreCommandRouter::volumioGetState Dec 28 15:28:33 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:35 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:35 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:35 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:35 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11124. Dec 28 15:28:35 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:35 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:35 volumio-jason go-librespot[16496]: Librespot-go daemon starting... Dec 28 15:28:35 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:35+09:00" level=info msg="generated new device id: 2393d685519c6b806c17e5e188d2c169d5345121" Dec 28 15:28:35 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:35+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:36 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:36+09:00" level=debug msg="obtained new client token: AADhpb/R5cyDj7EkoAKL2VHFDa3s0K2eoZ0Fc6KkJN+S7TeOz0KhUwOZOn59mUP5gWD12Ck5wr+W6fGQ6tvIMxIlv3DnrX2vtqjVOmaJxbVGc5Qa/PMXoPzA5kLJFXzEybX9yeGN4LpW4gIhZiU11eUPjUrwglKiQMxBmxcxrC6op5JwAjl5YsYMlGCSaXZwDotdbvzO1qpDK/f5Bve6AV7hKNZGR3GhprbrRr5/FHtD6eK+1Mk6JDBU2Xq0" Dec 28 15:28:37 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:37+09: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]" Dec 28 15:28:37 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:37+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:37 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:37+09:00" level=debug msg="completed challenge" Dec 28 15:28:37 volumio-jason go-librespot[16496]: time="2025-12-28T15:28:37+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:37 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:37 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:38 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:38 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:41 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:41 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11125. Dec 28 15:28:41 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:41 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:41 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:41 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:41 volumio-jason go-librespot[16504]: Librespot-go daemon starting... Dec 28 15:28:41 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:41+09:00" level=info msg="generated new device id: e28bcb45c355524ecbaa25c98cc74d17ae4404b8" Dec 28 15:28:41 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:41+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:41 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:41 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:41 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:41 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:41 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:41 volumio-jason volumio[862]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 28 15:28:41 volumio-jason volumio[862]: info: peppy_screensaver: Start PeppyMeter Dec 28 15:28:42 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:42+09:00" level=debug msg="obtained new client token: AAAPgrifF0zjUH8ea4kuPS0S/iX2EP0RgcgvKBAzt6/Q1lma0ICXhuQEELBkxHUgOsLm9/5hjHs/yVNY+ZP/8lKrjaNZ93ayQ5kjEMwz18swAAHvcn+rC9nkF8MCLbaPXnzKpgXxgkzolqbQ7sEjmXLBtb2ekYLGjIu67CsWgd9g87alXb+4UWasSdW4kQPAEtdd+XGZW6HMrAOvK23fSw4HHDeTOXssENf3r4OKvVhCsLc9+CTCwNLzfO1KOpI=" Dec 28 15:28:42 volumio-jason volumio[862]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Dec 28 15:28:42 volumio-jason volumio[862]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason shairport-sync[1108]: {"time":1766903114455,"response":"startAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 15:28:43 volumio-jason shairport-sync[1108]: Dload Upload Total Spent Left Speed Dec 28 15:28:43 volumio-jason volumio[862]: info: Dec 28 15:28:43 volumio-jason volumio[862]: ---------------------------- Client requests Stop Airplay Playback Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Dec 28 15:28:43 volumio-jason volumio[862]: info: Airplay playback stop Dec 28 15:28:43 volumio-jason volumio[862]: info: Airplay Playback Stopped, clearing state Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::resetVolumioState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::getcurrentVolume Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 15:28:43 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:43+09: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]" Dec 28 15:28:43 volumio-jason shairport-sync[1108]: [158B blob data] Dec 28 15:28:43 volumio-jason volumio[862]: error: [now-playing] No images found in My Backgrounds Dec 28 15:28:43 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:43+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:43 volumio-jason volumio[862]: info: VolumeController:: Volume=78 Mute =false Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::updateTrackBlock Dec 28 15:28:43 volumio-jason volumio[862]: info: CorePlayQueue::getTrackBlock Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason volumio[862]: info: VolumeController:: Volume=78 Mute =false Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:43 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:43 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:43 volumio-jason volumio[862]: info: MyVolumio login type: Token Dec 28 15:28:44 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:44+09:00" level=debug msg="completed challenge" Dec 28 15:28:44 volumio-jason go-librespot[16504]: time="2025-12-28T15:28:44+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:44 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:44 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:44 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:44 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:45 volumio-jason volumio[862]: info: Airplay started streaming, receiving metadatas Dec 28 15:28:45 volumio-jason volumio[862]: info: Airplay started streaming, receiving metadatas Dec 28 15:28:45 volumio-jason shairport-sync[1108]: {"time":1766903323501,"response":"stopAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 15:28:45 volumio-jason shairport-sync[1108]: Dload Upload Total Spent Left Speed Dec 28 15:28:45 volumio-jason volumio[862]: info: Dec 28 15:28:45 volumio-jason volumio[862]: ---------------------------- Client requests Start Airplay PlaybackRoutine Dec 28 15:28:45 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Dec 28 15:28:45 volumio-jason volumio[862]: info: Airplay playback start Dec 28 15:28:45 volumio-jason shairport-sync[1108]: [158B blob data] Dec 28 15:28:45 volumio-jason kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Dec 28 15:28:45 volumio-jason kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:46 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:46 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:46 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:46 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:46 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:46 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:47 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:47 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:47 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11126. Dec 28 15:28:47 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:47 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:47 volumio-jason go-librespot[16539]: Librespot-go daemon starting... Dec 28 15:28:47 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:47+09:00" level=info msg="generated new device id: 8ebc3a98a6e73524f3066fe43db7478515282daa" Dec 28 15:28:47 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:47+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:47 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:47 volumio-jason volumio[862]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Dec 28 15:28:47 volumio-jason volumio[862]: at MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:75:19) Dec 28 15:28:47 volumio-jason volumio[862]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:113:37) Dec 28 15:28:47 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:47:13 Dec 28 15:28:47 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:47 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:144:13) Dec 28 15:28:47 volumio-jason volumio[862]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:114:3) Dec 28 15:28:47 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:47 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Dec 28 15:28:47 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Dec 28 15:28:47 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Dec 28 15:28:47 volumio-jason volumio[862]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Dec 28 15:28:47 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Dec 28 15:28:47 volumio-jason volumio[862]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Dec 28 15:28:47 volumio-jason volumio[862]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Dec 28 15:28:47 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:47 volumio-jason volumio[862]: error: [now-playing] No images found in My Backgrounds Dec 28 15:28:48 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:48+09:00" level=debug msg="obtained new client token: AACuMjHydmF3YQx3D7JNrgJTGZlOxAwl6J0QAoG/+GqOAFHznJwlKJvU6rsk1Nf5CEQJHgGtJWVvOxHldeiuDIzCIrvyHS1+9s59OoA+di7/G26fevkXyFKRwWME4Qv2nfc6OjyFfoooANp4QBm4rZiWkHqrKd61JsNW4fCHTrXB254wwpfGHxr0bVkHbdjqZqZLzXfC03RJrHOlLSk1DnAWwGzLU/RDqZHOpP8tfHBcGRA3zbp+tJYJKv14" Dec 28 15:28:49 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:49+09: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]" Dec 28 15:28:49 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:49+09:00" level=debug msg="completed keyexchange" Dec 28 15:28:49 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:49+09:00" level=debug msg="completed challenge" Dec 28 15:28:49 volumio-jason go-librespot[16539]: time="2025-12-28T15:28:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 28 15:28:49 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:49 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:50 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:50 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:51 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:51 volumio-jason volumio[862]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Dec 28 15:28:51 volumio-jason volumio[862]: at MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:75:19) Dec 28 15:28:51 volumio-jason volumio[862]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:113:37) Dec 28 15:28:51 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:47:13 Dec 28 15:28:51 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:51 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:144:13) Dec 28 15:28:51 volumio-jason volumio[862]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:114:3) Dec 28 15:28:51 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:51 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Dec 28 15:28:51 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Dec 28 15:28:51 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Dec 28 15:28:51 volumio-jason volumio[862]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Dec 28 15:28:51 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Dec 28 15:28:51 volumio-jason volumio[862]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Dec 28 15:28:51 volumio-jason volumio[862]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Dec 28 15:28:51 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:51 volumio-jason volumio[862]: error: [now-playing] No images found in My Backgrounds Dec 28 15:28:53 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:53 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11127. Dec 28 15:28:53 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:53 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:53 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:53 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:53 volumio-jason go-librespot[16547]: Librespot-go daemon starting... Dec 28 15:28:53 volumio-jason go-librespot[16547]: time="2025-12-28T15:28:53+09:00" level=info msg="generated new device id: 9f59df5bdf7c72ca9b49ac16449f752f03fd89cf" Dec 28 15:28:53 volumio-jason go-librespot[16547]: time="2025-12-28T15:28:53+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:54 volumio-jason go-librespot[16547]: time="2025-12-28T15:28:54+09:00" level=debug msg="obtained new client token: AADdCwlrXZo7p/dVC4MfwkA0cg7nSeccQ3bkjZknJ0fSGC8XUq8Bn4tvJb2jVLyGVyLpjuDR+dWFbiHQ4G5/zlN0TcZD8/oE47vvFSIR4flmyOetqD7oPwg6DTn7yIBWt8ApQZK+YqMKtzduLwz7iWMh3I8esBYfVZGpWys7L5rHUNMeJdOCMpdWUpxOU9A4dJ1pxG98ySvq245ZoliHbV22mG2f2YvCluFvQGguLW7asS/dkL7hjOgD9Qd6" Dec 28 15:28:55 volumio-jason go-librespot[16547]: time="2025-12-28T15:28:55+09: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]" Dec 28 15:28:55 volumio-jason go-librespot[16547]: time="2025-12-28T15:28:55+09: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" Dec 28 15:28:55 volumio-jason systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 15:28:55 volumio-jason systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 15:28:56 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:56 volumio-jason volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 15:28:58 volumio-jason systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 15:28:58 volumio-jason systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11128. Dec 28 15:28:58 volumio-jason systemd[1]: Stopped go-librespot Daemon. Dec 28 15:28:58 volumio-jason systemd[1]: Started go-librespot Daemon. Dec 28 15:28:58 volumio-jason go-librespot[16558]: Librespot-go daemon starting... Dec 28 15:28:58 volumio-jason go-librespot[16558]: time="2025-12-28T15:28:58+09:00" level=info msg="generated new device id: 76f12758b720177be72597ff338559bfbb0f00ec" Dec 28 15:28:58 volumio-jason go-librespot[16558]: time="2025-12-28T15:28:58+09:00" level=debug msg="stored credentials not found" Dec 28 15:28:59 volumio-jason volumio[862]: info: Initializing connection to go-librespot Websocket Dec 28 15:28:59 volumio-jason go-librespot[16558]: time="2025-12-28T15:28:59+09:00" level=debug msg="new websocket client" Dec 28 15:28:59 volumio-jason volumio[862]: info: Connection to go-librespot Websocket established Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::servicePushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreStateMachine::pushState Dec 28 15:28:59 volumio-jason volumio[862]: info: CoreCommandRouter::volumioPushState Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Dec 28 15:28:59 volumio-jason volumio[862]: error: [now-playing] No images found in My Backgrounds Dec 28 15:28:59 volumio-jason volumio[862]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Dec 28 15:28:59 volumio-jason volumio[862]: at MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:75:19) Dec 28 15:28:59 volumio-jason volumio[862]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:113:37) Dec 28 15:28:59 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:47:13 Dec 28 15:28:59 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:59 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:144:13) Dec 28 15:28:59 volumio-jason volumio[862]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:114:3) Dec 28 15:28:59 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:28:59 volumio-jason volumio[862]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Dec 28 15:28:59 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Dec 28 15:28:59 volumio-jason volumio[862]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Dec 28 15:28:59 volumio-jason volumio[862]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Dec 28 15:28:59 volumio-jason volumio[862]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Dec 28 15:28:59 volumio-jason volumio[862]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Dec 28 15:28:59 volumio-jason volumio[862]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Dec 28 15:28:59 volumio-jason volumio[862]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Dec 28 15:29:00 volumio-jason volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 8 Dec 28 15:29:00 volumio-jason volumio[862]: info: CoreCommandRouter::volumioGetState Dec 28 15:29:00 volumio-jason go-librespot[16558]: time="2025-12-28T15:29:00+09:00" level=debug msg="obtained new client token: AACn9wJTSSZZPRFjzcNNACO+yOAbOeN11H0dhCnDzsxwwSyT/x4SiL4CCMEeBHXZHw5nGiwg72i5Yqtu+xaFHuuDp2RUeiMr4LNXbhitxUamkS5JjEdL6Ahn2TuA6gDb3U9lqWEg03fE26I0101hXGh3kUMfjaleWWKR7nAViSrxD1E9zeEQH1tt/LjuLAMWJBGgeTBPuvWwdQK8ZePRx56qw4U7JbFM0fwmfkawHROfrarcu2rH/Z9oam7p" Dec 28 15:29:01 volumio-jason volumio[862]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 15:29:01 volumio-jason volumio[862]: Error: connect ETIMEDOUT 31.13.87.34:443 Dec 28 15:29:01 volumio-jason volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Dec 28 15:29:01 volumio-jason volumio[862]: errno: -110, Dec 28 15:29:01 volumio-jason volumio[862]: code: 'ETIMEDOUT', Dec 28 15:29:01 volumio-jason volumio[862]: syscall: 'connect', Dec 28 15:29:01 volumio-jason volumio[862]: address: '31.13.87.34', Dec 28 15:29:01 volumio-jason volumio[862]: port: 443 Dec 28 15:29:01 volumio-jason volumio[862]: } Dec 28 15:29:01 volumio-jason volumio[862]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 15:29:01 volumio-jason go-librespot[16558]: time="2025-12-28T15:29:01+09: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]" Dec 28 15:29:01 volumio-jason go-librespot[16558]: time="2025-12-28T15:29:01+09:00" level=debug msg="completed keyexchange" Dec 28 15:29:01 volumio-jason sudo[16601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-28 15:28 Dec 28 15:29:01 volumio-jason sudo[16601]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"