-- Logs begin at Tue 2024-10-29 02:33:38 KST, end at Tue 2024-10-29 04:47:36 KST. -- Oct 29 04:46:01 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:01 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99031. Oct 29 04:46:01 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:01 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: Librespot-go daemon starting... Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=info msg="generated new device id: a1746725bfd07cc567c2250db3b14a05692f6abe" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:01 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="new websocket client" Oct 29 04:46:01 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="zeroconf server listening on port 45221" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="obtained new client token: AAApGDZb7nkyl+hYc9RipzJipIxjZ8BAFi5hommTED1CLlJURyDYqNkESaw4HVDGgg0S0X/Al5GpUpTRfpWqR2hh/auWjiRd8yvEgsH4bQ/r7pDHZPJLBJhrqwB/nLZ6qaJtITY28XQM6rSJ4pD+39gjh1eFIQR3RJA2WzVq5H8AZh+ZmP2k2HCrFoe21zcXzU/zp3zC9VGzFRdAu5j2I8WBRis4vtjDzxT1HkBnLOBZhdi6QzTTFUgzshqRxQ==" Oct 29 04:46:01 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:01+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:02 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:02+09:00" level=debug msg="completed challenge" Oct 29 04:46:02 volumio-ap3 go-librespot[30154]: time="2024-10-29T04:46:02+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:02 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:46:04 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:46:04 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:04 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:46:04 volumio-ap3 volumio[1070]: (node:1070) 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: 23771) Oct 29 04:46:04 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:46:04 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:46:04 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:46:05 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:05 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:05 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:05 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99032. Oct 29 04:46:05 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:05 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:05 volumio-ap3 go-librespot[30162]: Librespot-go daemon starting... Oct 29 04:46:05 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:05+09:00" level=info msg="generated new device id: 4b8915839baaf5ef64273c77f6b877168960933d" Oct 29 04:46:05 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:05+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+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]" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="zeroconf server listening on port 36815" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="obtained new client token: AACT/4wKo2QRnJHN7OVu3r0G1abeAi1uvQ29H1QZRDyimAiV5JX42Wf3ph8G7PO8vzGBx1XdJlYXXVvJFZ5hsnlDuPens515dPfM7Up+5u2JlD8RKM2ndszbRyA7f1XlSdg5UeW72Kgy9mt2CkQBe0yt9LmzWdZ7kmbgvjQdzWF1io8NhOhLtG7hZcLuMWzMmzOkhhtKZHqSMIAScAlboxNqYUgpCaSffdhEEw93OdGlnDMdPKIs/Srp9Lg=" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:06 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:06+09:00" level=debug msg="completed challenge" Oct 29 04:46:07 volumio-ap3 go-librespot[30162]: time="2024-10-29T04:46:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:08 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:08 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99033. Oct 29 04:46:10 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:10 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: Librespot-go daemon starting... Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=info msg="generated new device id: c1f99503f7f7359c37ca0482fa4f68eefce62bfa" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+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]" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="zeroconf server listening on port 42831" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="obtained new client token: AACV0zBgufVVCrDheH1rPF1GfnH0QO/5//RDEXtagZ58EEGhoS/gqtdOs+pybuvdutR3AuFZ7pl+ur/50zyRw1zIlmwyqxSWRtAKdyAHKpRAB2EdxFI5gCFsiEFDAXrqtmrZ4AWolKsob5pFlvbX/TzCT64SKuUMRZlAeMx9gKDUhvpYwJX1dPL3gzz845ROZfs30ioGwAcaZcdlO2B//rckbmtIAz/Qh8ikMNKIKCkLAG+Q3o8sDTTSuBfLLQ==" Oct 29 04:46:10 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:10+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:11 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:11+09:00" level=debug msg="completed challenge" Oct 29 04:46:11 volumio-ap3 go-librespot[30171]: time="2024-10-29T04:46:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:11 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:11 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:14 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:14 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99034. Oct 29 04:46:14 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:14 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: Librespot-go daemon starting... Oct 29 04:46:14 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:14 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+09:00" level=info msg="generated new device id: aba5eec4100aa6ceb35710dcdc03642843050306" Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+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]" Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 29 04:46:14 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:14+09:00" level=debug msg="zeroconf server listening on port 46727" Oct 29 04:46:15 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:15+09:00" level=debug msg="obtained new client token: AACpxCgR9qHjQ+KX9Wg65qjzHQFg4HQTzK6XoN6I/CqglmBi+YPgVyWly0ZbBmldC+VK4CsI2Ih/ahjE3iHZUTyWQHsbhdhGvcRbePELhyoDxau8z7cyzjev6MjBJNOMKiS31NsGahvQCHaGNwwGOPHgo3NicT2WqgyUylkRRGcuq5l37K+BzCkQZ90eUtEqcv/BcS7DtgSAQIyHbCowa2hlviUhZnabctUOEElsUm/DD0bWdmrhw5RRdxs=" Oct 29 04:46:15 volumio-ap3 go-librespot[30180]: time="2024-10-29T04:46:15+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" Oct 29 04:46:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:17 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:17 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:18 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:18 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99035. Oct 29 04:46:18 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:18 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: Librespot-go daemon starting... Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=info msg="generated new device id: 8d3114c73ebbe4de45225eee7d03db30811f1d2b" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+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]" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="zeroconf server listening on port 42425" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="obtained new client token: AABV+F66m7I8l9k7+I9qOeKSlhm0qQgtb46JgZXWQQEwQf7waB5A3IVUFz3yO0+GPmdC8UKeFeJPWNsxcw4tlvzMsF5AMZfcLqkwsZrlrY/G3YkpRQlUNY7/lP7hH3jfWzDLkQdra9+KTYzz48Vok0tT4fmMxUu2WcOGjzTzJTBswie/Jz8+hd1hLenovmUe4GE9Ygiqqh3AgUsJM9+kdbr8j1R05M2d7anvdKlRhoyAjYS1lTZz5WXdRtSa9A==" Oct 29 04:46:18 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:18+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:19 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:19+09:00" level=debug msg="completed challenge" Oct 29 04:46:19 volumio-ap3 go-librespot[30188]: time="2024-10-29T04:46:19+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:20 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:20 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:22 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:22 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99036. Oct 29 04:46:22 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:22 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:22 volumio-ap3 go-librespot[30196]: Librespot-go daemon starting... Oct 29 04:46:22 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:22+09:00" level=info msg="generated new device id: aed8f82f871540ca50b3052cac6f5c5abccb8a40" Oct 29 04:46:22 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:22+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="zeroconf server listening on port 45353" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="obtained new client token: AADwWWpICtD4S9TaCwdTCk/oVbmL+siSLTjZhxo23M+QaZxHVjadFCGaC06MGXEwr8lcNDyxXTL5IHDOM4HsMl8slbqY4kbbYHUPXRnY4T2uxsnCJg3V2leHfsMvEHTfdci/vWCDDl9qjlzofDBX7lgehawE7UYJXWNA2LJpMusOZ30rbIP4KSfNanuj6E+S4W4zEmtoZgZrBO/2j6AkHUfSiLvcSZOT8NL0SvEOiz8ZvMA3CJ3VXdItDWCFSQ==" Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:23 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="new websocket client" Oct 29 04:46:23 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:46:23 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:23+09:00" level=debug msg="completed challenge" Oct 29 04:46:24 volumio-ap3 go-librespot[30196]: time="2024-10-29T04:46:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:24 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:46:26 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:46:26 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:26 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:46:26 volumio-ap3 volumio[1070]: (node:1070) 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: 23772) Oct 29 04:46:26 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:46:26 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:46:26 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:46:27 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:27 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99037. Oct 29 04:46:27 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:27 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: Librespot-go daemon starting... Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=info msg="generated new device id: f8722c2423051a3a0a9228fbd26f115b6096e701" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+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]" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=debug msg="zeroconf server listening on port 39479" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+09:00" level=debug msg="obtained new client token: AAATKs3bz/L2jEf0BZdk5Ytdg5E+nsFz9St8AocWN800hsPl9OxImhBIrDcho16+EKD6QUXzvTpe8SVr6pg+DpI7WXNU4JcNT5Pbfwg02khOs5CHGz3vTa2emvF/ypuqogv9xwehLiXkGpdfvCcl1wq8Xe3JvCNQ2ntnTbJRzYvpAqe1RP2c5OiOUlMwYvtP87Q/bFXZfzig8Y9WxoqFhucWOJoxJEbANMR+P1Jgx3hE5JttB3HMdq1plfqXGQ==" Oct 29 04:46:27 volumio-ap3 go-librespot[30205]: time="2024-10-29T04:46:27+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" Oct 29 04:46:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:30 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:30 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:31 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:31 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99038. Oct 29 04:46:31 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:31 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: Librespot-go daemon starting... Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=info msg="generated new device id: 778ce969e6f919f8fe3baf41392364a96f62226d" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="zeroconf server listening on port 34801" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="obtained new client token: AACofXZMoKf3/cJkpiicVnNvtAo6qAWQLcRcTBBwumyqLWTKIosNFWnxJDtYJkrbhTzAMgxX7LsyKupscMJpUuQwM/nN5m2v3kjxW7pO2i+A4x+3X72MbrMcVTEtfgTV3FCWFNea/8mJoS8B1seB93b75ss+OWQCOMEqPbf3UVxb4vBVK3KnFVt+A8Qpzo5CBTkHV6udeWPode5w4rREgx7l5q7gYCW0/ytdqMfotbYm27p8WwetIlZT8ufxPw==" Oct 29 04:46:31 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:31+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:32 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:32+09:00" level=debug msg="completed challenge" Oct 29 04:46:32 volumio-ap3 go-librespot[30213]: time="2024-10-29T04:46:32+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:33 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:33 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:35 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:35 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99039. Oct 29 04:46:35 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:35 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: Librespot-go daemon starting... Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+09:00" level=info msg="generated new device id: 7db8c7aadeec33f0a03072a53c3a6477463c067a" Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+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]" Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:35 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:35+09:00" level=debug msg="zeroconf server listening on port 34227" Oct 29 04:46:36 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:36 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:36+09:00" level=debug msg="new websocket client" Oct 29 04:46:36 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:46:36 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:36+09:00" level=debug msg="obtained new client token: AABEkyC52AZp4woIz4be7WT/AwcUvggrekO30uqQ24TpC7ZJI0fSM8v1jsnab0ZHbzQCedxUSemallUAPQW+fWCEXu7tyIGxZk9QMZ2dK3lkHU7Kr4hXDpMXGschLe7rBlPWQvH0x8dDV9/JnDsMN3Xosc3Rep1+0DIVEQnKKI37vfcHUe5Pqw4uRwfYVF8mUMbcubR7hTic2evDTRTYN/GVfQWFk9+zQqFIQe0BL4UDzE8dXmw8gnYRu40=" Oct 29 04:46:36 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:36+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:36 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:36+09:00" level=debug msg="completed challenge" Oct 29 04:46:36 volumio-ap3 go-librespot[30222]: time="2024-10-29T04:46:36+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:36 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:46:39 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:46:39 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:39 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:46:39 volumio-ap3 volumio[1070]: (node:1070) 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: 23773) Oct 29 04:46:39 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:46:39 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:46:39 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:46:39 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:39 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99040. Oct 29 04:46:40 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:40 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: Librespot-go daemon starting... Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=info msg="generated new device id: 071d54baf0a33a0e13d5fbeccdc85855e7af863e" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+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]" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=debug msg="zeroconf server listening on port 41063" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+09:00" level=debug msg="obtained new client token: AADcHdsKAtFR4LSfyFyA7E3suROCnEvdJ1EnWUgw6tqC/N7tSuMLsoqgBol2Ha0oJpT2k39pseYp9F/jKRz/OodXA5o8hRcCjqxIMQ/CfHLapwh8m9ypSLwCfGVVn/7c4kKOdz/ZiWMMPkYOwclAbpc1bhxAbVGabdRGEvGCSMnqy/Hu1Vl2R4KnMM5LqspwdOx7nE/CCdtMyj0bjTaxliuzNw+n/y5G1coddRrE/QyIDIE5dnNPfZ8ljlmwPQ==" Oct 29 04:46:40 volumio-ap3 go-librespot[30270]: time="2024-10-29T04:46:40+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" Oct 29 04:46:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:42 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:42 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:43 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:43 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99041. Oct 29 04:46:43 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:43 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:43 volumio-ap3 go-librespot[30278]: Librespot-go daemon starting... Oct 29 04:46:43 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:43+09:00" level=info msg="generated new device id: 64a6ed1c2df10c30ac0bdf4ecf396d8028b74abc" Oct 29 04:46:43 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:43+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+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-gew4.spotify.com:80]" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="zeroconf server listening on port 43783" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="obtained new client token: AABoGlOr8TWTzdkeF6V7R466vkvPw83YFJNn9r52xQqX4FFwjGbXSIQIwFVxDgfgB0uKscU7kiou71dtFmjuNIUd/qhpqwv5AIKmH9t+canC/BxtPgejkA0+UE46zka2ZnrQMM20e8eNEOkscemCAiYeatUdRSLbKuGpZ7TvAJx2feKQfLfbAzh9LBj/5MSfRze+F35WgKJ7A6Mj80ulnSyLO7gnZA/jzHzbTa+yvnA0GcI6UKhMHDEhuAE=" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=debug msg="completed challenge" Oct 29 04:46:44 volumio-ap3 go-librespot[30278]: time="2024-10-29T04:46:44+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:44 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:44 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:45 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:45 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:48 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:48 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99042. Oct 29 04:46:48 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:48 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: Librespot-go daemon starting... Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=info msg="generated new device id: 420977d7074969f897243045669cc81e818c2d74" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+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]" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="zeroconf server listening on port 44781" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="obtained new client token: AACr20QkcE9kyEQaAGQbnLIFsY8GbNT/VmeDaC3gVq1ZeX0ffmqPSS5er0iV7YxX1dRZJULBnFc4w/J3tT7VcExQZ3PAv/LyjOiRb4NAQPf6HIAo49W89MiQyxNw95c1VMQJRpu5wNH0SFRSL/QnjKqplXvHtx+VR7m6yLdtqLBU1ib62Xx7ybHpktDFbXgX3uvXWdoeyViEdeyKe2CofqtYKysR1mhO3aFAQcta+fBf4oK2AwFTfW44abZeYg==" Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:48 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:48 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:48+09:00" level=debug msg="new websocket client" Oct 29 04:46:48 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:46:49 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:49+09:00" level=debug msg="completed challenge" Oct 29 04:46:49 volumio-ap3 go-librespot[30286]: time="2024-10-29T04:46:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:49 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:49 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:46:49 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:51 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:46:51 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:51 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:46:51 volumio-ap3 volumio[1070]: (node:1070) 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: 23774) Oct 29 04:46:51 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:46:51 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:46:51 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:46:52 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:52 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:52 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:52 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99043. Oct 29 04:46:52 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:52 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: Librespot-go daemon starting... Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+09:00" level=info msg="generated new device id: cf73bae65f99578bfaa1e76d4b034e9b382625cc" Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+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]" Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:52 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:52+09:00" level=debug msg="zeroconf server listening on port 42479" Oct 29 04:46:53 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:53+09:00" level=debug msg="obtained new client token: AABrcXgle3wEwTBb+rsz7leCmEuMEva9cQigHai682rEohxy6NHGlgZy5CwdMAS1pudcaLrTyQtAg8Va2Q02w+Vu5bS7tL1Nhk/nuqpht3Qz4JApy38PN/Stex+50We9uOJJs6zdp1Q7Kj0tHChLOPcqV2Nc2MYT6HcOAXknEwazbVcBI7oxo5vcRwuPHf6cHtIo2foa9qakXRs9j+p+UPPhFkP1bNhZAtGjymLSwjYnM8yMcDteI/4+XSc=" Oct 29 04:46:53 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:53+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:53 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:53+09:00" level=debug msg="completed challenge" Oct 29 04:46:53 volumio-ap3 go-librespot[30295]: time="2024-10-29T04:46:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:53 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:53 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:55 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:55 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:46:57 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:46:57 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99044. Oct 29 04:46:57 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:46:57 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: Librespot-go daemon starting... Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=info msg="generated new device id: 946b417eff0fc42d1e8014e552356ad0a449814a" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+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]" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="zeroconf server listening on port 41981" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="obtained new client token: AADtAj8/d5exim8ulUWzGt5dL7G8ARpsgRC9ghjXBKoN7/oojIjZA7GEFy03EibWNudzxTEdMrZ1ffbfJsJOH3loZOQStefF48+DUd06xS0HLWE77pNn8P6LTnAZwN/20Es/BQIfMSXYB6a2L4uEdYDhsCi4edSgLvC/dtSLnDSco9Za3IIMcHRpnndrjQkedRNFEUUmqOCdlu+3//nLY+737v9L415qKK8KjaRlJK5kZR180KETWFjPDaMgSQ==" Oct 29 04:46:57 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:57+09:00" level=debug msg="completed keyexchange" Oct 29 04:46:58 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:58+09:00" level=debug msg="completed challenge" Oct 29 04:46:58 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:46:58 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:58+09:00" level=debug msg="new websocket client" Oct 29 04:46:58 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:46:58 volumio-ap3 go-librespot[30304]: time="2024-10-29T04:46:58+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:46:58 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:46:58 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:46:58 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:47:01 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:47:01 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:01 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:47:01 volumio-ap3 volumio[1070]: (node:1070) 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: 23775) Oct 29 04:47:01 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:47:01 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:47:01 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:01 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:01 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:01 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:01 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99045. Oct 29 04:47:01 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:01 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:01 volumio-ap3 go-librespot[30313]: Librespot-go daemon starting... Oct 29 04:47:01 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:01+09:00" level=info msg="generated new device id: 59e61bb5128bf7b3efb9902543aff9b2fab77fca" Oct 29 04:47:01 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:01+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+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]" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="zeroconf server listening on port 33789" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="obtained new client token: AADuxs+84bQ08nwO7HhPD1QUuPog5WEMyicI8CFDsUZyR5b2ahHbrtV4LptPw08F5ScqunyVgQ5KfroiXrPxZzXHeI6oHaCVuJmy7D7ftvNFl6MI2Wt0/2esYuUQfqIPMP9xkrNlmHMler1BIOaTE+xtIohTXp183i0ToqgirjCYg6m3LaerQpbGPqOQymASUHaByoSZb2TIr1eedvY5lfaO0/fDTG65k1vo++CLXHyV1klo7GQXqSlFxBY=" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:02 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:02+09:00" level=debug msg="completed challenge" Oct 29 04:47:03 volumio-ap3 go-librespot[30313]: time="2024-10-29T04:47:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:47:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:04 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:04 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99046. Oct 29 04:47:06 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:06 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: Librespot-go daemon starting... Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=info msg="generated new device id: 15eef6f2b391e79f933b74ec0143b8bda735f093" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+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]" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="zeroconf server listening on port 41373" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="obtained new client token: AAA9T8hHkuyUZZuSlYLtKnMOjrMB/zIcNRlzuNe70PwIBuexVAkbv7dsI8o80wyzpFuoqf8kyg32bClpZaYdYgwNtjPjh5YtyBjYOODECzyISKZm/HDBSj8LWuAV6W4o+eW4s1QoiJdrCQ2pAFfcV2JtwVJqx1NL6SnC7psoOlrak+oBu6U0MS/77ubaVMXR0eCzUYVoMGVsHLliqDKGaVybmr28RAOZNCJVsevzl63lWlpbcqTTxFLwyC3m5g==" Oct 29 04:47:06 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:06+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:07 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:07+09:00" level=debug msg="completed challenge" Oct 29 04:47:07 volumio-ap3 go-librespot[30321]: time="2024-10-29T04:47:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:47:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:07 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:07 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:10 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:10 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99047. Oct 29 04:47:10 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:10 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:10 volumio-ap3 go-librespot[30332]: Librespot-go daemon starting... Oct 29 04:47:10 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:10+09:00" level=info msg="generated new device id: 40ada4d0cde8d69f10d3c40e8fea0f2bf735dd17" Oct 29 04:47:10 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:10+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+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]" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="zeroconf server listening on port 45005" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="obtained new client token: AAD9oG240hgSmvWSGn8NVmtNC/Pw02y87WEjAcE/jUXYIkdJir4UqdhE8Zq9MND+F7PvATSAMHKEMJv7POJRI1afDJlWNiGPEtrI5U8MrIkXy/F5yJO6oN+X4XPRl2PrCAEpahjzN95ilv6O0Rh9gjXyaVV3jQV9989uAQwkjauHHUz6nZSRlEDdSX0wqGQDQ4QB8PSgykYvnHC3dG/ZXf+ZBHBG45x/PhSye58VCwilLd9jDjX9ujrQLE0=" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=debug msg="completed challenge" Oct 29 04:47:11 volumio-ap3 go-librespot[30332]: time="2024-10-29T04:47:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:47:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:13 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:13 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99048. Oct 29 04:47:15 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:15 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: Librespot-go daemon starting... Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=info msg="generated new device id: 6e82e700c1daa91acdf68564be09f9cb57185418" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+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-gew4.spotify.com:80]" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="zeroconf server listening on port 41743" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="obtained new client token: AAAl5wp4mCS5u3DUfhAaeH2MAZNiXHwsqn2Z5KGSgMumuGG9W4VNJGZ37VL2z3QcTsAjAsHAblEWrLfob3NKEX4QL/DJ/QafFfg3cATXExNbU5smsZAKso+ZXENEtcPFkZ0WnGREFKaD0FIH1jFOsUsYPjnkEOYYzutZCOc2lcKSBa34l7bjFr9NYWAbdeectUGvMPT2fL+cGnCjq/uB9ud2+NNS+mBQYHQPIkw3901wIPGO1kZDG7dW/WupTQ==" Oct 29 04:47:15 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:15+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:16 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:16+09:00" level=debug msg="completed challenge" Oct 29 04:47:16 volumio-ap3 go-librespot[30341]: time="2024-10-29T04:47:16+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:47:16 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:16 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:16 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:16 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99049. Oct 29 04:47:19 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:19 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: Librespot-go daemon starting... Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=info msg="generated new device id: 93b1783634774e96ae5bd7ba8f0d706add4021cc" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+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]" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="zeroconf server listening on port 39745" Oct 29 04:47:19 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="new websocket client" Oct 29 04:47:19 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="obtained new client token: AACo27PN8iVkmkx6mTWrm//CyxQ9/n+dLmyS45lFiXNQWHCPOJMaItd8rHvC3aoHgKNnNg76i8ZrOGBdsKTkTzizD9W1KOyHmYQBJJdSDuieXbh8e+ikbDI8vBum0JxFb05MxCnzlGJ4Ua5JeM31KmcBtztKO+V4PyC4Y0JfN1/pb76M257C+F1zuBY0Ufw2OJeJyVOiSD4VSxW13pUn5i9JEMZcEqHGYyiMkjKYHbHJJaBlkKyDFg6E/55StA==" Oct 29 04:47:19 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:19+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:20 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:20+09:00" level=debug msg="completed challenge" Oct 29 04:47:20 volumio-ap3 go-librespot[30349]: time="2024-10-29T04:47:20+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 29 04:47:20 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket closed Oct 29 04:47:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:22 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:47:22 volumio-ap3 volumio[1070]: (node:1070) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:22 volumio-ap3 volumio[1070]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 04:47:22 volumio-ap3 volumio[1070]: (node:1070) 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: 23776) Oct 29 04:47:22 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:47:22 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:47:22 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:23 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:23 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99050. Oct 29 04:47:23 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:23 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: Librespot-go daemon starting... Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:23+09:00" level=info msg="generated new device id: 1877efa579328d567bacba844ee80fc013a13dc5" Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:23+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:23+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:23+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 29 04:47:23 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:23+09:00" level=debug msg="zeroconf server listening on port 36395" Oct 29 04:47:24 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:24+09:00" level=debug msg="obtained new client token: AABX7z3T5qFLnM+qIsfu8kAgUlLATXMnTczys9GeB3QJHWMzFoCRoj/zmXurPitS2Z83+3eGp6J/HMiVTMxc1BcAVpy5Q2n5Np5CFas2CQ6vEYkPziv3P23h5X0jM9QZYn3MLf75kU30IbAxh7LlSFLl2kFB2T0z2tXCfv2NqFOASC1fp8o9317s/6/YBRTYIXz8sQ2IMhX7iLpV0m5Br82iJxH10ZMTyeFgEFNh62wSpEL+zEoEhUDhALo=" Oct 29 04:47:24 volumio-ap3 go-librespot[30357]: time="2024-10-29T04:47:24+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" Oct 29 04:47:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:26 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:26 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99051. Oct 29 04:47:27 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:27 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: Librespot-go daemon starting... Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=info msg="generated new device id: 600d1ca5b54ffe18d2a0a5dcf9e50f58bef42ac5" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+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]" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="zeroconf server listening on port 37935" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="obtained new client token: AACr9BvLGIpVWPk3j0BzRAkwau5wjZn0uczxJJtFjbNPUOmo5req1O4ZEX2WXu9OLqMGH4JJ/hNcyinSjRgDHRv8h/0d0P6Ws7K/P24m3GXcQN2usfLxeGvLL5I58biZsYOZFBkx9qOFwNTsGal7W35OCo1T5xa19oKF+HIY46V2QpjI4VfEQ1xdaBvc2yuDw6AKebn0MlR56jvjgArepr70xz2vfzY5C9TK22NfbzDwOs/mq6pjs6BGt2vD+Q==" Oct 29 04:47:27 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:27+09:00" level=debug msg="completed keyexchange" Oct 29 04:47:28 volumio-ap3 go-librespot[30365]: time="2024-10-29T04:47:28+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed solving challenge: failed login: BadCredentials" Oct 29 04:47:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 04:47:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: Clearing queue after UPNP request Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CoreStateMachine::ClearQueue Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CoreStateMachine::stop Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CorePlayQueue::clearPlayQueue Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CorePlayQueue::saveQueue Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioPushState Oct 29 04:47:28 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioPushQueue Oct 29 04:47:28 volumio-ap3 volumio[1070]: error: Upnp client error: Error: This socket has been ended by the other party Oct 29 04:47:29 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:29 volumio-ap3 volumio[1070]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Starting UPNP Playback Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Preparing playback through UPNP Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 11ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 7ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 6ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 5ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 3ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 5ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 3ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 5ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 3ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Oct 29 04:47:30 volumio-ap3 volumio[1070]: ---------------------------- MPD announces system playlist update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: Ignoring MPD Status Update Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 5ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 4ms Oct 29 04:47:30 volumio-ap3 volumio[1070]: info: ------------------------------ 3ms Oct 29 04:47:31 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 04:47:31 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99052. Oct 29 04:47:31 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Oct 29 04:47:31 volumio-ap3 systemd[1]: Started go-librespot Daemon. Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: Librespot-go daemon starting... Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=info msg="generated new device id: fa1aa20c12d3543cbd6ec2a17a60b3c40179574e" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47: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]" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=debug msg="zeroconf server listening on port 36547" Oct 29 04:47:31 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:31+09:00" level=debug msg="obtained new client token: AABXObRnpcma0UfPEInCuuXRk7UocXVYey8KyDdr/c31rdaqRjYS1pKob1pOpPKGVDgXlGgyuWxQiO3FqauLXahmZNxyAh6TJWdQito01qc6wGhMjvor0QOi5dC/SZgltH0LidXG3u7nbxj1IBsqf7BytjFndWABvnE2ZzQ6q4lDWliX64EzC0EI48PecNKgqgT/XdQR3BYO3u2CFiwZg5MVRu8U0UNim47m/8qWN5t+S6l6WHRrubvnBSzP1g==" Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 11 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 7 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Oct 29 04:47:32 volumio-ap3 volumio[1070]: ---------------------------- MPD announces state update: player Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::getState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand status Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Initializing connection to go-librespot Websocket Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 22 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 19 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 8 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand status took 7 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus stop Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Received an update from plugin. extracting info from payload Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 50ms Oct 29 04:47:32 volumio-ap3 volumio[1070]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 45ms Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: sendMpdCommand playlistinfo took 19 milliseconds Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: ControllerMpd::parseTrackInfo Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Received an update from plugin. extracting info from payload Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Received an update from plugin. extracting info from payload Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":880,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Received an update from plugin. extracting info from payload Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ControllerMpd::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreCommandRouter::servicePushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: In UPNP mode Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: STATE SERVICE {"status":"play","position":1,"seek":880,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8","trackType":"m3u8"} Oct 29 04:47:32 volumio-ap3 volumio[1070]: verbose: CURRENT POSITION 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState stateService play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::syncState currentStatus play Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Received an update from plugin. extracting info from payload Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CoreStateMachine::pushState Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:32 volumio-ap3 volumio[1070]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 29 04:47:32 volumio-ap3 volumio[1070]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 29 04:47:32 volumio-ap3 volumio[1070]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 64ms Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 61ms Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 49ms Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: ------------------------------ 45ms Oct 29 04:47:32 volumio-ap3 go-librespot[30380]: time="2024-10-29T04:47:32+09:00" level=debug msg="new websocket client" Oct 29 04:47:32 volumio-ap3 volumio[1070]: info: Connection to go-librespot Websocket established Oct 29 04:47:35 volumio-ap3 volumio[1070]: info: Getting Spotify volume Oct 29 04:47:35 volumio-ap3 volumio[1070]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 29 04:47:35 volumio-ap3 volumio[1070]: info: CoreCommandRouter::volumioGetState Oct 29 04:47:35 volumio-ap3 volumio[1070]: info: CorePlayQueue::getTrack 0 Oct 29 04:47:35 volumio-ap3 volumio[1070]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 04:47:35 volumio-ap3 volumio[1070]: TypeError: Cannot read property 'name' of undefined Oct 29 04:47:35 volumio-ap3 volumio[1070]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Oct 29 04:47:35 volumio-ap3 volumio[1070]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:107:28) Oct 29 04:47:35 volumio-ap3 volumio[1070]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:58:38) Oct 29 04:47:35 volumio-ap3 volumio[1070]: at Socket.emit (events.js:315:20) Oct 29 04:47:35 volumio-ap3 volumio[1070]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 29 04:47:35 volumio-ap3 volumio[1070]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 29 04:47:35 volumio-ap3 volumio[1070]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 04:47:36 volumio-ap3 sudo[30429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-29 04:46 Oct 29 04:47:36 volumio-ap3 sudo[30429]: 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="8b17c2f054b42f7617d19172c51eb8801fef450d" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="5ed89c6e5067f886280d87d6c1a3f9930df14028" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 16 Oct 2024 03:57:06 PM CEST" VOLUMIO_VERSION="3.765" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="0d32cf437531a99146c655ee44a741a6"