-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Mon 2024-08-19 14:43:38 UTC. -- Aug 19 14:42:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 19 14:42:02 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:02 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:02 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:02 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:02 volumio go-librespot[1810]: Librespot-go daemon starting... Aug 19 14:42:02 volumio go-librespot[1810]: time="2024-08-19T14:42:02Z" level=info msg="generated new device id: 480cc6fe74d06324b26f0214448fe7c44abf9487" Aug 19 14:42:02 volumio go-librespot[1810]: time="2024-08-19T14:42:02Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:02 volumio go-librespot[1810]: time="2024-08-19T14:42:02Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:05 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:05 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 19 14:42:05 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:05 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:05 volumio go-librespot[1817]: Librespot-go daemon starting... Aug 19 14:42:05 volumio go-librespot[1817]: time="2024-08-19T14:42:05Z" level=info msg="generated new device id: 0b0f9f4a3f8e7c99ce06d8106ede03cc69d17ab7" Aug 19 14:42:05 volumio go-librespot[1817]: time="2024-08-19T14:42:05Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:05 volumio go-librespot[1817]: time="2024-08-19T14:42:05Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:08 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:08 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 19 14:42:08 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:08 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:08 volumio go-librespot[1824]: Librespot-go daemon starting... Aug 19 14:42:08 volumio go-librespot[1824]: time="2024-08-19T14:42:08Z" level=info msg="generated new device id: 04ad5ef4a80d16a453c1f6b231b6bf54c2e34602" Aug 19 14:42:08 volumio go-librespot[1824]: time="2024-08-19T14:42:08Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:08 volumio go-librespot[1824]: time="2024-08-19T14:42:08Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:11 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:11 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 19 14:42:11 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:11 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:11 volumio go-librespot[1832]: Librespot-go daemon starting... Aug 19 14:42:11 volumio go-librespot[1832]: time="2024-08-19T14:42:11Z" level=info msg="generated new device id: c821796c5d0fcf66921c0c6cecdb53ca7e1b240c" Aug 19 14:42:11 volumio go-librespot[1832]: time="2024-08-19T14:42:11Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:11 volumio go-librespot[1832]: time="2024-08-19T14:42:11Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:14 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:14 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 19 14:42:15 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:15 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:15 volumio go-librespot[1839]: Librespot-go daemon starting... Aug 19 14:42:15 volumio go-librespot[1839]: time="2024-08-19T14:42:15Z" level=info msg="generated new device id: 6e7c4304b733258de2513ea74f196d103c94db82" Aug 19 14:42:15 volumio go-librespot[1839]: time="2024-08-19T14:42:15Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:15 volumio go-librespot[1839]: time="2024-08-19T14:42:15Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:16 volumio systemd[1]: nmbd.service: Start operation timed out. Terminating. Aug 19 14:42:16 volumio systemd[1]: nmbd.service: Main process exited, code=killed, status=15/TERM Aug 19 14:42:16 volumio systemd[1]: nmbd.service: Failed with result 'timeout'. Aug 19 14:42:16 volumio systemd[1]: Failed to start Samba NMB Daemon. Aug 19 14:42:16 volumio systemd[1]: Starting Samba Winbind Daemon... Aug 19 14:42:16 volumio winbindd[1846]: [2024/08/19 14:42:16.889341, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Aug 19 14:42:16 volumio winbindd[1846]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 19 14:42:16 volumio winbindd[1846]: [2024/08/19 14:42:16.903422, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 19 14:42:16 volumio winbindd[1846]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Aug 19 14:42:16 volumio systemd[1]: Started Samba Winbind Daemon. Aug 19 14:42:16 volumio systemd[1]: Starting Samba SMB Daemon... Aug 19 14:42:17 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:17 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:17 volumio smbd[1851]: [2024/08/19 14:42:17.253413, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 19 14:42:17 volumio smbd[1851]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Aug 19 14:42:17 volumio systemd[1]: Started Samba SMB Daemon. Aug 19 14:42:17 volumio systemd[1]: Reached target Multi-User System. Aug 19 14:42:17 volumio systemd[1]: Reached target Graphical Interface. Aug 19 14:42:17 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 19 14:42:17 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 19 14:42:17 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 19 14:42:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 19 14:42:18 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:18 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:18 volumio go-librespot[1860]: Librespot-go daemon starting... Aug 19 14:42:18 volumio go-librespot[1860]: time="2024-08-19T14:42:18Z" level=info msg="generated new device id: df1e389861bcadb7a70221d391438894b7a7b9aa" Aug 19 14:42:18 volumio go-librespot[1860]: time="2024-08-19T14:42:18Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:18 volumio go-librespot[1860]: time="2024-08-19T14:42:18Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:20 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:20 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 19 14:42:21 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:21 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:21 volumio go-librespot[1868]: Librespot-go daemon starting... Aug 19 14:42:21 volumio go-librespot[1868]: time="2024-08-19T14:42:21Z" level=info msg="generated new device id: 91c22ebf3fb63046fadf09b863d4a3010749a7c8" Aug 19 14:42:21 volumio go-librespot[1868]: time="2024-08-19T14:42:21Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:21 volumio go-librespot[1868]: time="2024-08-19T14:42:21Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:23 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:23 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 19 14:42:24 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:24 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:24 volumio go-librespot[1876]: Librespot-go daemon starting... Aug 19 14:42:24 volumio go-librespot[1876]: time="2024-08-19T14:42:24Z" level=info msg="generated new device id: 2324b35e10301751078fb5baae1b9c462a03bf84" Aug 19 14:42:24 volumio go-librespot[1876]: time="2024-08-19T14:42:24Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:24 volumio go-librespot[1876]: time="2024-08-19T14:42:24Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:26 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:26 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:27 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:27 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 19 14:42:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 19 14:42:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:28 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:28 volumio go-librespot[1884]: Librespot-go daemon starting... Aug 19 14:42:28 volumio go-librespot[1884]: time="2024-08-19T14:42:28Z" level=info msg="generated new device id: 6d7efbec8b6caa5666e0ea94c1b4a16e9e0f0cc3" Aug 19 14:42:28 volumio go-librespot[1884]: time="2024-08-19T14:42:28Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:28 volumio go-librespot[1884]: time="2024-08-19T14:42:28Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:29 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:29 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 19 14:42:31 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:31 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:31 volumio go-librespot[1891]: Librespot-go daemon starting... Aug 19 14:42:31 volumio go-librespot[1891]: time="2024-08-19T14:42:31Z" level=info msg="generated new device id: aecd0472d65de6532eaafe8defed9d56f9b3b742" Aug 19 14:42:31 volumio go-librespot[1891]: time="2024-08-19T14:42:31Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:31 volumio go-librespot[1891]: time="2024-08-19T14:42:31Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:32 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:32 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 19 14:42:34 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:34 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:34 volumio go-librespot[1899]: Librespot-go daemon starting... Aug 19 14:42:34 volumio go-librespot[1899]: time="2024-08-19T14:42:34Z" level=info msg="generated new device id: 4def3f645be294ace536a45050c52881e4a79e1e" Aug 19 14:42:34 volumio go-librespot[1899]: time="2024-08-19T14:42:34Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:34 volumio go-librespot[1899]: time="2024-08-19T14:42:34Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:35 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:35 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 19 14:42:37 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:37 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:37 volumio go-librespot[1908]: Librespot-go daemon starting... Aug 19 14:42:37 volumio go-librespot[1908]: time="2024-08-19T14:42:37Z" level=info msg="generated new device id: a97709a42026e6a6436197d0943e37a645b5e913" Aug 19 14:42:37 volumio go-librespot[1908]: time="2024-08-19T14:42:37Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:37 volumio go-librespot[1908]: time="2024-08-19T14:42:37Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:38 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:38 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 19 14:42:41 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:41 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:41 volumio go-librespot[1916]: Librespot-go daemon starting... Aug 19 14:42:41 volumio go-librespot[1916]: time="2024-08-19T14:42:41Z" level=info msg="generated new device id: 97a44ebed4207b2bf72bd5c5e40e226c81cf0081" Aug 19 14:42:41 volumio go-librespot[1916]: time="2024-08-19T14:42:41Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:41 volumio go-librespot[1916]: time="2024-08-19T14:42:41Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:41 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:41 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:41 volumio wpa_supplicant[912]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="fcompt" Aug 19 14:42:41 volumio wpa_supplicant[912]: wlan0: Trying to associate with SSID 'fcompt' Aug 19 14:42:43 volumio wpa_supplicant[912]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 19 14:42:43 volumio wpa_supplicant[912]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="fcompt" auth_failures=4 duration=77 reason=CONN_FAILED Aug 19 14:42:44 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:44 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 19 14:42:44 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:44 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:44 volumio go-librespot[1925]: Librespot-go daemon starting... Aug 19 14:42:44 volumio go-librespot[1925]: time="2024-08-19T14:42:44Z" level=info msg="generated new device id: 9ceb4dedafc38ee3c2d7821a312d70a4699a3296" Aug 19 14:42:44 volumio go-librespot[1925]: time="2024-08-19T14:42:44Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:44 volumio go-librespot[1925]: time="2024-08-19T14:42:44Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:47 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:47 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 19 14:42:47 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:47 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:47 volumio go-librespot[1974]: Librespot-go daemon starting... Aug 19 14:42:47 volumio go-librespot[1974]: time="2024-08-19T14:42:47Z" level=info msg="generated new device id: 07dfaa20cccca21415f4254b2153bbc886e713bc" Aug 19 14:42:47 volumio go-librespot[1974]: time="2024-08-19T14:42:47Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:47 volumio go-librespot[1974]: time="2024-08-19T14:42:47Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:48 volumio volumio[988]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 19 14:42:48 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 19 14:42:49 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Aug 19 14:42:49 volumio sudo[1984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Aug 19 14:42:49 volumio sudo[1984]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[1991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:42:49 volumio sudo[1991]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[1996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:42:49 volumio sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[1984]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio sudo[1991]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio sudo[1996]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio sudo[2002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:42:49 volumio sudo[2002]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[2002]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio sudo[2009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 19 14:42:49 volumio sudo[2009]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[2009]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 19 14:42:49 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 19 14:42:49 volumio sudo[2012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 19 14:42:49 volumio sudo[2012]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:49 volumio sudo[2012]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:49 volumio sudo[2016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 19 14:42:49 volumio sudo[2016]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:50 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:50 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 19 14:42:50 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:50 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:50 volumio go-librespot[2018]: Librespot-go daemon starting... Aug 19 14:42:50 volumio go-librespot[2018]: time="2024-08-19T14:42:50Z" level=info msg="generated new device id: 688d7d6cf745a34bdd540fb4afdbd37ab71fdd06" Aug 19 14:42:50 volumio go-librespot[2018]: time="2024-08-19T14:42:50Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:50 volumio go-librespot[2018]: time="2024-08-19T14:42:50Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:51 volumio sudo[2016]: pam_unix(sudo:session): session closed for user root Aug 19 14:42:53 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:53 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 19 14:42:54 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:54 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:54 volumio go-librespot[2025]: Librespot-go daemon starting... Aug 19 14:42:54 volumio go-librespot[2025]: time="2024-08-19T14:42:54Z" level=info msg="generated new device id: e83f0e0e3bbe4dde47d31cc71ec64d6d30e2a71d" Aug 19 14:42:54 volumio go-librespot[2025]: time="2024-08-19T14:42:54Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:54 volumio go-librespot[2025]: time="2024-08-19T14:42:54Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:56 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:56 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:42:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 19 14:42:57 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:42:57 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:42:57 volumio go-librespot[2032]: Librespot-go daemon starting... Aug 19 14:42:57 volumio go-librespot[2032]: time="2024-08-19T14:42:57Z" level=info msg="generated new device id: abb777c808d4ad8545262bbfe4b93694d51ac63d" Aug 19 14:42:57 volumio go-librespot[2032]: time="2024-08-19T14:42:57Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:42:57 volumio go-librespot[2032]: time="2024-08-19T14:42:57Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:42:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:42:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:42:57 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 19 14:42:57 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 19 14:42:57 volumio sudo[2040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 19 14:42:57 volumio sudo[2040]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:42:59 volumio ntpd[814]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Aug 19 14:42:59 volumio ntpd[814]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Aug 19 14:42:59 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:42:59 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:42:59 volumio sudo[2040]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:00 volumio ntpd[814]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Aug 19 14:43:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 19 14:43:00 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:00 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:00 volumio go-librespot[2042]: Librespot-go daemon starting... Aug 19 14:43:00 volumio go-librespot[2042]: time="2024-08-19T14:43:00Z" level=info msg="generated new device id: fcd143530246ae3c83e4bd72b2a47886370c2fdf" Aug 19 14:43:00 volumio go-librespot[2042]: time="2024-08-19T14:43:00Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:00 volumio go-librespot[2042]: time="2024-08-19T14:43:00Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:02 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:02 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:03 volumio ntpd[814]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Aug 19 14:43:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 19 14:43:03 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:03 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:03 volumio go-librespot[2049]: Librespot-go daemon starting... Aug 19 14:43:03 volumio go-librespot[2049]: time="2024-08-19T14:43:03Z" level=info msg="generated new device id: 9bc807244955b64080349f6f0f682894ef543a62" Aug 19 14:43:03 volumio go-librespot[2049]: time="2024-08-19T14:43:03Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:03 volumio go-librespot[2049]: time="2024-08-19T14:43:03Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:05 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:05 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Aug 19 14:43:07 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:07 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:07 volumio go-librespot[2056]: Librespot-go daemon starting... Aug 19 14:43:07 volumio go-librespot[2056]: time="2024-08-19T14:43:07Z" level=info msg="generated new device id: 9b0b261530b5e484a603ce20364a95d1651dd3f0" Aug 19 14:43:07 volumio go-librespot[2056]: time="2024-08-19T14:43:07Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:07 volumio go-librespot[2056]: time="2024-08-19T14:43:07Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:07 volumio volumio[988]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 19 14:43:07 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 19 14:43:07 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Aug 19 14:43:07 volumio sudo[2067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Aug 19 14:43:07 volumio sudo[2067]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:07 volumio sudo[2067]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:07 volumio sudo[2073]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:43:07 volumio sudo[2073]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:07 volumio sudo[2073]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:07 volumio sudo[2079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:43:07 volumio sudo[2079]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:07 volumio sudo[2079]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:07 volumio sudo[2085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 19 14:43:07 volumio sudo[2085]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:07 volumio sudo[2085]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:07 volumio sudo[2092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 19 14:43:07 volumio sudo[2092]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:07 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 19 14:43:07 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 19 14:43:07 volumio sudo[2092]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:08 volumio sudo[2095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 19 14:43:08 volumio sudo[2095]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:08 volumio sudo[2095]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:08 volumio sudo[2099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 19 14:43:08 volumio sudo[2099]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:08 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:08 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:10 volumio sudo[2099]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Aug 19 14:43:10 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:10 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:10 volumio go-librespot[2101]: Librespot-go daemon starting... Aug 19 14:43:10 volumio go-librespot[2101]: time="2024-08-19T14:43:10Z" level=info msg="generated new device id: aa0de0906203bc595f9c7e75c3d70bc8ea404dbf" Aug 19 14:43:10 volumio go-librespot[2101]: time="2024-08-19T14:43:10Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:10 volumio go-librespot[2101]: time="2024-08-19T14:43:10Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:11 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:11 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Aug 19 14:43:13 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:13 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:13 volumio go-librespot[2108]: Librespot-go daemon starting... Aug 19 14:43:13 volumio go-librespot[2108]: time="2024-08-19T14:43:13Z" level=info msg="generated new device id: 507e12de43f8b49bc833d14f5f7b8eb52f0bd8ca" Aug 19 14:43:13 volumio go-librespot[2108]: time="2024-08-19T14:43:13Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:13 volumio go-librespot[2108]: time="2024-08-19T14:43:13Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:14 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:14 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Aug 19 14:43:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:16 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:16 volumio go-librespot[2116]: Librespot-go daemon starting... Aug 19 14:43:16 volumio go-librespot[2116]: time="2024-08-19T14:43:16Z" level=info msg="generated new device id: 7554a4a1c8f8f59492fdffd0454b36fba3b07f8a" Aug 19 14:43:16 volumio go-librespot[2116]: time="2024-08-19T14:43:16Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:16 volumio go-librespot[2116]: time="2024-08-19T14:43:16Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:17 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:17 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Aug 19 14:43:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:20 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:20 volumio go-librespot[2124]: Librespot-go daemon starting... Aug 19 14:43:20 volumio go-librespot[2124]: time="2024-08-19T14:43:20Z" level=info msg="generated new device id: 0119b8c3394167cc2e39022f8f10f541fef14b53" Aug 19 14:43:20 volumio go-librespot[2124]: time="2024-08-19T14:43:20Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:20 volumio go-librespot[2124]: time="2024-08-19T14:43:20Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:20 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:20 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:23 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:23 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Aug 19 14:43:23 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:23 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:23 volumio go-librespot[2133]: Librespot-go daemon starting... Aug 19 14:43:23 volumio go-librespot[2133]: time="2024-08-19T14:43:23Z" level=info msg="generated new device id: e4c4ac968bd57f10c6d2f8008f8bac3ea5caeea7" Aug 19 14:43:23 volumio go-librespot[2133]: time="2024-08-19T14:43:23Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:23 volumio go-librespot[2133]: time="2024-08-19T14:43:23Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:24 volumio dhcpcd[924]: eth0: carrier acquired Aug 19 14:43:24 volumio dhcpcd[924]: DUID 00:01:00:01:2e:31:51:de:e4:5f:01:fd:12:1f Aug 19 14:43:24 volumio dhcpcd[924]: eth0: IAID 01:fd:12:1f Aug 19 14:43:24 volumio dhcpcd[924]: eth0: adding address fe80::2cc:957b:defb:38ed Aug 19 14:43:24 volumio dhcpcd[924]: ipv6_addaddr1: Permission denied Aug 19 14:43:24 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Aug 19 14:43:24 volumio ifplugd(eth0)[812]: Link beat detected. Aug 19 14:43:24 volumio ifplugd(eth0)[812]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Aug 19 14:43:24 volumio dhcpcd[2162]: sending commands to master dhcpcd process Aug 19 14:43:24 volumio dhcpcd[924]: control command: /sbin/dhcpcd eth0 Aug 19 14:43:24 volumio ifplugd(eth0)[812]: client: sending commands to master dhcpcd process Aug 19 14:43:24 volumio ifplugd(eth0)[812]: Program executed successfully. Aug 19 14:43:24 volumio dhcpcd[924]: eth0: soliciting an IPv6 router Aug 19 14:43:25 volumio dhcpcd[924]: eth0: rebinding lease of 192.168.1.170 Aug 19 14:43:25 volumio dhcpcd[924]: eth0: probing address 192.168.1.170/24 Aug 19 14:43:26 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:26 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Aug 19 14:43:26 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:26 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:26 volumio go-librespot[2187]: Librespot-go daemon starting... Aug 19 14:43:26 volumio go-librespot[2187]: time="2024-08-19T14:43:26Z" level=info msg="generated new device id: 14b7cbdf49de5d8ddc61243e02fdae918de1b896" Aug 19 14:43:26 volumio go-librespot[2187]: time="2024-08-19T14:43:26Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:26 volumio go-librespot[2187]: time="2024-08-19T14:43:26Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:29 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:29 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Aug 19 14:43:29 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:29 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:29 volumio go-librespot[2194]: Librespot-go daemon starting... Aug 19 14:43:29 volumio go-librespot[2194]: time="2024-08-19T14:43:29Z" level=info msg="generated new device id: 10bf37f2b7c74fee1de519fb55ceb731880add58" Aug 19 14:43:29 volumio go-librespot[2194]: time="2024-08-19T14:43:29Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:29 volumio go-librespot[2194]: time="2024-08-19T14:43:29Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 19 14:43:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 19 14:43:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 19 14:43:30 volumio dhcpcd[924]: eth0: leased 192.168.1.170 for 172800 seconds Aug 19 14:43:30 volumio dhcpcd[924]: eth0: adding route to 192.168.1.0/24 Aug 19 14:43:30 volumio dhcpcd[924]: eth0: adding default route via 192.168.1.252 Aug 19 14:43:30 volumio avahi-daemon[669]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.170. Aug 19 14:43:30 volumio avahi-daemon[669]: New relevant interface eth0.IPv4 for mDNS. Aug 19 14:43:30 volumio avahi-daemon[669]: Registering new address record for 192.168.1.170 on eth0.IPv4. Aug 19 14:43:31 volumio volumio[988]: info: Discovery: adding b4f144c1-da61-4d2f-b023-aa5bcc8461fc Aug 19 14:43:31 volumio volumio[988]: info: Discovery: Found device Volumio Aug 19 14:43:31 volumio volumio[988]: info: CoreCommandRouter::volumioGetState Aug 19 14:43:31 volumio volumio[988]: info: CorePlayQueue::getTrack 0 Aug 19 14:43:32 volumio ntpd[814]: Listen normally on 3 eth0 192.168.1.170:123 Aug 19 14:43:32 volumio ntpd[814]: new interface(s) found: waking up resolver Aug 19 14:43:32 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:32 volumio volumio[988]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 19 14:43:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 19 14:43:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Aug 19 14:43:33 volumio systemd[1]: Stopped go-librespot Daemon. Aug 19 14:43:33 volumio systemd[1]: Started go-librespot Daemon. Aug 19 14:43:33 volumio go-librespot[2228]: Librespot-go daemon starting... Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=info msg="generated new device id: d23a61ad33f5301951f2d208b5df1226452ba826" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="stored credentials found for filipecompt" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="zeroconf server listening on port 38773" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="obtained new client token: AADktd9AZRX6GzEpEdz5ayeGi9kC6/uW9QeUU8UoTCSgAYAfmYq6rB96FU71Gy4ym78uNTnKAiEgnQvswFkzyQFIOvicirZJP8WgtxjMpw+fYOivXGjCpdRwmFh6L/xnV5dqAnWP2BF3u8WAkiIs/Rm2E48DvzNMbGk3dlWKd1ZcTvq3YQuEl9LnnGivc8C0gKYYssBOv5UPRgxaydOTCsNbKDI510NGMUrzcMRoTzQf6M78oFjzieS/CA==" Aug 19 14:43:33 volumio go-librespot[2228]: time="2024-08-19T14:43:33Z" level=debug msg="completed keyexchange" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="completed challenge" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="authenticated as filipecompt" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="authenticated as filipecompt" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="dealer connection opened" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="initializing zeroconf session, username: filipecompt" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="autoplay enabled: false" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="received connection id: YTEyZWQ5MzgtNmJhYS00ZWQzLWE5NzMtOWRkZDhhNWRmMDVhK2RlYWxlcit0Y3A6Ly8wYWNhNDE4NS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMkI2QUE2NzNBNEE5QUE0RDVBNEZGQzFENUI5MzI4RkNDMjM5MzE1MTM5OERBMjMxMkU5NzEzN0QyNzg2RDEyNQ==" Aug 19 14:43:34 volumio go-librespot[2228]: time="2024-08-19T14:43:34Z" level=debug msg="put connect state because NEW_DEVICE" Aug 19 14:43:35 volumio volumio[988]: info: Initializing connection to go-librespot Websocket Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=debug msg="new websocket client" Aug 19 14:43:35 volumio volumio[988]: info: Connection to go-librespot Websocket established Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=debug msg="handling transfer player command from 51c68448e9314e57d4ceebce3c2513ca48c8a039" Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=debug msg="resolved context of track" uri="spotify:playlist:0nwFsP30BQF2ULUfaTvnLg" Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=trace msg="fetched new page 0 with 159 items (list: 159)" uri="spotify:playlist:0nwFsP30BQF2ULUfaTvnLg" Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=debug msg="loading track (paused: false, position: -89808294ms)" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin bluetooth to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin multiroom to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin metavolumio to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin cd_controller to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 19 14:43:35 volumio volumio[988]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 19 14:43:35 volumio go-librespot[2228]: time="2024-08-19T14:43:35Z" level=trace msg="emitting websocket event: will_play" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="selected format OGG_VORBIS_320 (5e6ca610dabb1bf5df4ae4de46c02ef625d7ed85)" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="requested aes key for file 5e6ca610dabb1bf5df4ae4de46c02ef625d7ed85, gid: 46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="fetched first chunk of 21, total size is 10491512 bytes" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="created new output device" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=info msg="loaded track \"Lake Shore Drive\" (paused: false, position: -89808294ms, duration: 235173ms, prefetched: false)" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:46MX86XQqYCZRvwPpeq4Gi" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=trace msg="scheduling prefetch in 205s" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=trace msg="emitting websocket event: metadata" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=trace msg="emitting websocket event: active" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="sending successful reply for dealer request" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=trace msg="emitting websocket event: playing" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 19 14:43:36 volumio go-librespot[2228]: time="2024-08-19T14:43:36Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1364" Aug 19 14:43:36 volumio volumio[988]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 19 14:43:36 volumio volumio[988]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 19 14:43:36 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 19 14:43:36 volumio volumio[988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 19 14:43:36 volumio volumio[988]: info: Starting MyVolumio Remote Streaming Endpoints Aug 19 14:43:36 volumio volumio[988]: info: MyVolumio login type: Token Aug 19 14:43:36 volumio volumio[988]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 19 14:43:36 volumio volumio[988]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 19 14:43:37 volumio go-librespot[2228]: time="2024-08-19T14:43:37Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 19 14:43:37 volumio go-librespot[2228]: time="2024-08-19T14:43:37Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1136" Aug 19 14:43:37 volumio volumio[988]: info: Starting Streaming Service Transparent Proxy Aug 19 14:43:37 volumio volumio[988]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 19 14:43:37 volumio volumio[988]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 19 14:43:37 volumio volumio[988]: info: Streaming services startup Aug 19 14:43:37 volumio volumio[988]: info: Starting Streaming Daemon Aug 19 14:43:37 volumio sudo[2246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 19 14:43:37 volumio sudo[2246]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 19 14:43:37 volumio sudo[2246]: pam_unix(sudo:session): session closed for user root Aug 19 14:43:37 volumio volumio[988]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 19 14:43:37 volumio volumio[988]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:46MX86XQqYCZRvwPpeq4Gi","play_origin":"playlist"}} Aug 19 14:43:37 volumio volumio[988]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:46MX86XQqYCZRvwPpeq4Gi","name":"Lake Shore Drive","artist_names":["Aliotta Haynes Jeremiah"],"album_name":"Lake Shore Drive","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bfd869b5a775481785ce55ad","position":-89808294,"duration":235173,"release_date":"year:1972","track_number":1,"disc_number":1}} Aug 19 14:43:37 volumio volumio[988]: SPOTIFY: received: {"type":"active","data":null} Aug 19 14:43:37 volumio volumio[988]: info: Aligning Spotify Volume to Volumio Volume Aug 19 14:43:37 volumio volumio[988]: info: CoreCommandRouter::volumioGetState Aug 19 14:43:37 volumio volumio[988]: info: CorePlayQueue::getTrack 0 Aug 19 14:43:37 volumio volumio[988]: info: Setting Spotify Volume from Volumio: 100 Aug 19 14:43:37 volumio volumio[988]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:46MX86XQqYCZRvwPpeq4Gi","play_origin":"playlist"}} Aug 19 14:43:37 volumio volumio[988]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 19 14:43:37 volumio volumio[988]: TypeError: Cannot read property 'service' of undefined Aug 19 14:43:37 volumio volumio[988]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Aug 19 14:43:37 volumio volumio[988]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Aug 19 14:43:37 volumio volumio[988]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Aug 19 14:43:37 volumio volumio[988]: at WebSocket.emit (events.js:315:20) Aug 19 14:43:37 volumio volumio[988]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Aug 19 14:43:37 volumio volumio[988]: at Receiver.emit (events.js:315:20) Aug 19 14:43:37 volumio volumio[988]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Aug 19 14:43:37 volumio volumio[988]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Aug 19 14:43:37 volumio volumio[988]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Aug 19 14:43:37 volumio volumio[988]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Aug 19 14:43:37 volumio volumio[988]: at writeOrBuffer (internal/streams/writable.js:358:12) Aug 19 14:43:37 volumio volumio[988]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Aug 19 14:43:37 volumio volumio[988]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Aug 19 14:43:37 volumio volumio[988]: at Socket.emit (events.js:315:20) Aug 19 14:43:37 volumio volumio[988]: at addChunk (internal/streams/readable.js:309:12) Aug 19 14:43:37 volumio volumio[988]: at readableAddChunk (internal/streams/readable.js:284:9) Aug 19 14:43:37 volumio volumio[988]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 19 14:43:38 volumio sudo[2262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-19 14:42 Aug 19 14:43:38 volumio sudo[2262]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"