-- Logs begin at Sun 2024-06-02 19:04:45 PDT, end at Thu 2024-07-11 03:10:51 PDT. -- Jul 11 03:09:03 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:03-07:00" level=debug msg="renewing login5 access token" Jul 11 03:09:03 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:03 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:03-07:00" level=error msg="did not receive last pong from dealer, 150s passed" Jul 11 03:09:10 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:18 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:19 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:19-07:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 10.0.0.26:44670->104.199.65.124:4070: read: connection timed out" Jul 11 03:09:19 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:19-07:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 11 03:09:21 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:21-07:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 11 03:09:23 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:23-07:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 11 03:09:25 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:25 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:25-07:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 11 03:09:28 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:28-07:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 11 03:09:32 volumio-2023 go-librespot[32164]: time="2024-07-11T03:09:32-07:00" level=error msg="did not receive last pong ack from accesspoint, 229s passed" Jul 11 03:09:32 volumio-2023 go-librespot[32164]: panic: runtime error: invalid memory address or nil pointer dereference Jul 11 03:09:32 volumio-2023 go-librespot[32164]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x455454] Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 29 [running]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: panic({0x5a3810, 0x9eea20}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:987 +0x414 fp=0x2050f1c sp=0x2050ec0 pc=0x4ee28 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.panicmem() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:260 +0x4c fp=0x2050f28 sp=0x2050f1c pc=0x4d5cc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.sigpanic() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/signal_unix.go:841 +0x26c fp=0x2050f44 sp=0x2050f28 pc=0x68750 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x221a120) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:310 +0x250 fp=0x2050fe4 sp=0x2050f48 pc=0x455454 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/ap.NewAccesspoint.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x28 fp=0x2050fec sp=0x2050fe4 pc=0x453674 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2050fec sp=0x2050fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by go-librespot/ap.NewAccesspoint Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x190 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 1 [select, 240 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x20b77e8 sp=0x20b77d4 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x20b7a6c, 0x20b79b0, 0x0, 0x0, 0x6, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x20b7890 sp=0x20b77e8 pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.(*AppPlayer).Run(0x2094480, 0x20961c0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:361 +0x1e4 fp=0x20b7eac sp=0x20b7890 pc=0x53c0d0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.(*App).withReusableCredentials(0x2158020, {0x5abe70, 0x20aa540}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:218 +0x660 fp=0x20b7f3c sp=0x20b7eac pc=0x5382f0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.(*App).SpotifyToken(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:159 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.main() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:331 +0x524 fp=0x20b7fc0 sp=0x20b7f3c pc=0x538cf8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.main() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:250 +0x268 fp=0x20b7fec sp=0x20b7fc0 pc=0x52288 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x20b7fec sp=0x20b7fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 2 [force gc (idle), 3 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f54, 0xa35150, 0x11, 0x14, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x203cfd8 sp=0x203cfc4 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goparkunlock(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.forcegchelper() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:305 +0xd4 fp=0x203cfec sp=0x203cfd8 pc=0x525d0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x203cfec sp=0x203cfec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.init.5 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:293 +0x1c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 18 [GC sweep wait]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f54, 0xa35750, 0xc, 0x14, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x20387c8 sp=0x20387b4 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goparkunlock(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.bgsweep(0x2062000) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcsweep.go:319 +0x104 fp=0x20387e4 sp=0x20387c8 pc=0x3c528 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcenable.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x28 fp=0x20387ec sp=0x20387e4 pc=0x2cff4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x20387ec sp=0x20387ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcenable Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x74 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 19 [GC scavenge wait]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f54, 0xa35a30, 0xd, 0x14, 0x2) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2038fb4 sp=0x2038fa0 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goparkunlock(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.(*scavengerState).park(0xa35a30) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:400 +0x64 fp=0x2038fc8 sp=0x2038fb4 pc=0x39e1c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.bgscavenge(0x2062000) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:633 +0x64 fp=0x2038fe4 sp=0x2038fc8 pc=0x3a560 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcenable.func2() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0x28 fp=0x2038fec sp=0x2038fe4 pc=0x2cfa0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2038fec sp=0x2038fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcenable Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0xbc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 20 [finalizer wait, 3875 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642e94, 0xa46af4, 0x10, 0x14, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x203c78c sp=0x203c778 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.runfinq() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:193 +0xfc fp=0x203c7ec sp=0x203c78c pc=0x2bed0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x203c7ec sp=0x203c7ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.createfing Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:163 +0x5c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 21 [IO wait, 18961 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f3c, 0xadcabf40, 0x2, 0x1b, 0x5) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x20395dc sp=0x20395c8 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.netpollblock(0xadcabf34, 0x72, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x20395f4 sp=0x20395dc pc=0x49f2c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.runtime_pollWait(0xadcabf34, 0x72) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2039608 sp=0x20395f4 pc=0x800b4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*pollDesc).wait(0x20a0ec4, 0x72, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x203961c sp=0x2039608 pc=0xf7db0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*pollDesc).waitRead(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*FD).Accept(0x20a0eb0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:614 +0x2d0 fp=0x203966c sp=0x203961c pc=0xfc8d0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*netFD).accept(0x20a0eb0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_unix.go:172 +0x20 fp=0x20396cc sp=0x203966c pc=0x281ba8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*TCPListener).accept(0x20aa530) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock_posix.go:148 +0x20 fp=0x20396e4 sp=0x20396cc pc=0x29a540 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*TCPListener).Accept(0x20aa530) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock.go:297 +0x30 fp=0x2039700 sp=0x20396e4 pc=0x299504 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.(*onceCloseListener).Accept(0x2182020) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: :1 +0x34 fp=0x2039718 sp=0x2039700 pc=0x427558 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.(*Server).Serve(0x218c000, {0x6ccfb0, 0x20aa530}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3059 +0x344 fp=0x20397b4 sp=0x2039718 pc=0x403550 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.Serve(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2581 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.(*ApiServer).serve(0x20939c0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:438 +0x62c fp=0x20397e4 sp=0x20397b4 pc=0x532118 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.NewApiServer.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x28 fp=0x20397ec sp=0x20397e4 pc=0x5317d0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x20397ec sp=0x20397ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by main.NewApiServer Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x1dc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 35 [GC worker (idle)]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642ea0, 0x2321cc8, 0x1a, 0x14, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2039f90 sp=0x2039f7c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcBgMarkWorker() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x2039fec sp=0x2039f90 pc=0x2fbb8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2039fec sp=0x2039fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcBgMarkStartWorkers Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 36 [GC worker (idle), 207 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642ea0, 0x2321ce0, 0x1a, 0x14, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x219e790 sp=0x219e77c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcBgMarkWorker() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x219e7ec sp=0x219e790 pc=0x2fbb8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x219e7ec sp=0x219e7ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcBgMarkStartWorkers Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 37 [GC worker (idle), 1077 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642ea0, 0x2321cf8, 0x1a, 0x14, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x219ef90 sp=0x219ef7c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcBgMarkWorker() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x219efec sp=0x219ef90 pc=0x2fbb8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x219efec sp=0x219efec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcBgMarkStartWorkers Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 38 [GC worker (idle), 2578 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642ea0, 0x2321d10, 0x1a, 0x14, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x219f790 sp=0x219f77c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gcBgMarkWorker() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x219f7ec sp=0x219f790 pc=0x2fbb8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x219f7ec sp=0x219f7ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by runtime.gcBgMarkStartWorkers Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 67 [select]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2202e7c sp=0x2202e68 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x2202fac, 0x2202f78, 0x0, 0x0, 0x2, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x2202f24 sp=0x2202e7c pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/dealer.(*Dealer).pingTicker(0x24dc090) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:105 +0x8c fp=0x2202fe4 sp=0x2202f24 pc=0x4783f4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/dealer.NewDealer.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x2202fec sp=0x2202fe4 pc=0x477d90 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2202fec sp=0x2202fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by go-librespot/dealer.NewDealer Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x174 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 68 [select, 18962 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x203d694 sp=0x203d680 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x203d7b0, 0x203d784, 0x0, 0x0, 0x2, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x203d73c sp=0x203d694 pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/player.(*Player).manageLoop(0x22a2380) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/player/player.go:102 +0xd4 fp=0x203d7e4 sp=0x203d73c pc=0x46922c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/player.NewPlayer.func2() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x28 fp=0x203d7ec sp=0x203d7e4 pc=0x469094 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x203d7ec sp=0x203d7ec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by go-librespot/player.NewPlayer Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x1bc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 76 [IO wait, 18961 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f3c, 0xadcabafc, 0x2, 0x1b, 0x5) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x21fe880 sp=0x21fe86c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.netpollblock(0xadcabaf0, 0x72, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x21fe898 sp=0x21fe880 pc=0x49f2c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.runtime_pollWait(0xadcabaf0, 0x72) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x21fe8ac sp=0x21fe898 pc=0x800b4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*pollDesc).wait(0x2524924, 0x72, 0x0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x21fe8c0 sp=0x21fe8ac pc=0xf7db0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*pollDesc).waitRead(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: internal/poll.(*FD).Read(0x2524910, {0x24f7000, 0x1000, 0x1000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x21fe910 sp=0x21fe8c0 pc=0xf8fbc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*netFD).Read(0x2524910, {0x24f7000, 0x1000, 0x1000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x21fe93c sp=0x21fe910 pc=0x27faec Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*conn).Read(0x2011d90, {0x24f7000, 0x1000, 0x1000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x21fe96c sp=0x21fe93c pc=0x290a70 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net.(*TCPConn).Read(0x2011d90, {0x24f7000, 0x1000, 0x1000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: :1 +0x44 fp=0x21fe98c sp=0x21fe96c pc=0x2a514c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: io.(*multiReader).Read(0x248a030, {0x24f7000, 0x1000, 0x1000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/multi.go:26 +0xac fp=0x21fe9c0 sp=0x21fe98c pc=0xf2de0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: bufio.(*Reader).fill(0x24bc660) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x21fe9e4 sp=0x21fe9c0 pc=0x144f14 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: bufio.(*Reader).ReadByte(0x24bc660) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x21fe9f0 sp=0x21fe9e4 pc=0x1457c4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.readFrameHeader(0x24bc660, {0x221c6f0, 0x8, 0x8}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x21fea30 sp=0x21fe9f0 pc=0x440024 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x221c6c0, {0x6cd2ac, 0x20a2020}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x21feaf0 sp=0x21fea30 pc=0x442b84 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).readLoop(0x221c6c0, {0x6cd2ac, 0x20a2020}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x21febb4 sp=0x21feaf0 pc=0x44265c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).reader(0x221c6c0, {0x6cd2ac, 0x20a2020}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x21fec40 sp=0x21febb4 pc=0x44389c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).Reader(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).Read(0x221c6c0, {0x6cd2ac, 0x20a2020}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x21fec68 sp=0x21fec40 pc=0x441f28 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: main.(*ApiServer).serve.func13({0x6cd0e4, 0x22423c0}, 0x20d1400) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:418 +0x24c fp=0x21fecc4 sp=0x21fec68 pc=0x5325d0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.HandlerFunc.ServeHTTP(0x2188058, {0x6cd0e4, 0x22423c0}, 0x20d1400) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2122 +0x34 fp=0x21fecd4 sp=0x21fecc4 pc=0x40026c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.(*ServeMux).ServeHTTP(0x2180000, {0x6cd0e4, 0x22423c0}, 0x20d1400) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2500 +0x164 fp=0x21fed00 sp=0x21fecd4 pc=0x401ab4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.serverHandler.ServeHTTP({0x218c000}, {0x6cd0e4, 0x22423c0}, 0x20d1400) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2936 +0x304 fp=0x21fed58 sp=0x21fed00 pc=0x402fc0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.(*conn).serve(0x2518f00, {0x6cd2ec, 0x2194000}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:1995 +0x654 fp=0x21fefdc sp=0x21fed58 pc=0x3feb34 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: net/http.(*Server).Serve.func3() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x38 fp=0x21fefec sp=0x21fefdc pc=0x4039f4 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x21fefec sp=0x21fefec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by net/http.(*Server).Serve Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x4e0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 78 [select, 18961 minutes]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x219dea0 sp=0x219de8c pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x219dfbc, 0x219df74, 0x0, 0x0, 0x5, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x219df48 sp=0x219dea0 pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x221c6c0) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x219dfe4 sp=0x219df48 pc=0x43d0c8 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: nhooyr.io/websocket.newConn.func2() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x219dfec sp=0x219dfe4 pc=0x43ccbc Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x219dfec sp=0x219dfec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by nhooyr.io/websocket.newConn Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 281 [select]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2200dd0 sp=0x2200dbc pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x2200ed0, 0x2200eb0, 0x0, 0x0, 0x2, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x2200e78 sp=0x2200dd0 pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x2200f1c, {0x6cc4c8, 0x2518f60}, 0x0, {0x0, 0x0}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x268 fp=0x2200ef4 sp=0x2200e78 pc=0x450c74 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x2200f78, {0x6cc4c8, 0x2518f60}, 0x0, {0x0, 0x0}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x2200f24 sp=0x2200ef4 pc=0x45070c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.RetryNotify(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.Retry(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/dealer.(*Dealer).recvLoop(0x24dc090) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:191 +0x564 fp=0x2200fe4 sp=0x2200f24 pc=0x478d58 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/dealer.(*Dealer).reconnect.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:241 +0x28 fp=0x2200fec sp=0x2200fe4 pc=0x4792b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2200fec sp=0x2200fec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by go-librespot/dealer.(*Dealer).reconnect Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:241 +0x78 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: goroutine 322 [select]: Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x204ddcc sp=0x204ddb8 pc=0x527b0 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.selectgo(0x204decc, 0x204deac, 0x0, 0x0, 0x2, 0x1) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x204de74 sp=0x204ddcc pc=0x64d80 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x204df18, {0x6cc4c8, 0x2519440}, 0x0, {0x0, 0x0}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x268 fp=0x204def0 sp=0x204de74 pc=0x450c74 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x204df74, {0x6cc4c8, 0x2519440}, 0x0, {0x0, 0x0}) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x204df20 sp=0x204def0 pc=0x45070c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.RetryNotify(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: github.com/cenkalti/backoff/v4.Retry(...) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/ap.(*Accesspoint).recvLoop(0x221a120) Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:277 +0x378 fp=0x204dfe4 sp=0x204df20 pc=0x454f3c Jul 11 03:09:32 volumio-2023 go-librespot[32164]: go-librespot/ap.(*Accesspoint).reconnect.func1() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:335 +0x28 fp=0x204dfec sp=0x204dfe4 pc=0x455778 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: runtime.goexit() Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x204dfec sp=0x204dfec pc=0x84730 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: created by go-librespot/ap.(*Accesspoint).reconnect Jul 11 03:09:32 volumio-2023 go-librespot[32164]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:335 +0x168 Jul 11 03:09:32 volumio-2023 go-librespot[32164]: Aborted Jul 11 03:09:32 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Jul 11 03:09:32 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:32 volumio-2023 volumio[1954]: info: Connection to go-librespot Websocket closed Jul 11 03:09:33 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:35 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:35 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:35 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:35 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jul 11 03:09:35 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:35 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:35 volumio-2023 go-librespot[4753]: Librespot-go daemon starting... Jul 11 03:09:35 volumio-2023 go-librespot[4753]: time="2024-07-11T03:09:35-07:00" level=info msg="generated new device id: 7afa045c6c7c60de8adf5cf1f6c2e9b50ef30824" Jul 11 03:09:35 volumio-2023 go-librespot[4753]: time="2024-07-11T03:09:35-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:35 volumio-2023 go-librespot[4753]: time="2024-07-11T03:09:35-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:35 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:35 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:38 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:38 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jul 11 03:09:39 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:39 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:39 volumio-2023 go-librespot[4760]: Librespot-go daemon starting... Jul 11 03:09:39 volumio-2023 go-librespot[4760]: time="2024-07-11T03:09:39-07:00" level=info msg="generated new device id: 7ad03f2a5f5efa90785a6e9dda7ae9443e388d01" Jul 11 03:09:39 volumio-2023 go-librespot[4760]: time="2024-07-11T03:09:39-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:39 volumio-2023 go-librespot[4760]: time="2024-07-11T03:09:39-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:40 volumio-2023 wpa_supplicant[775]: wlan0: Failed to initiate sched scan Jul 11 03:09:41 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:41 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:42 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:42 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jul 11 03:09:42 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:42 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:42 volumio-2023 go-librespot[4767]: Librespot-go daemon starting... Jul 11 03:09:42 volumio-2023 go-librespot[4767]: time="2024-07-11T03:09:42-07:00" level=info msg="generated new device id: cb4003fc1123788efad8cb9bc97169d2c2a2fbd6" Jul 11 03:09:42 volumio-2023 go-librespot[4767]: time="2024-07-11T03:09:42-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:42 volumio-2023 go-librespot[4767]: time="2024-07-11T03:09:42-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:42 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:42 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:44 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:44 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:45 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:45 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jul 11 03:09:45 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:45 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:45 volumio-2023 go-librespot[4775]: Librespot-go daemon starting... Jul 11 03:09:45 volumio-2023 go-librespot[4775]: time="2024-07-11T03:09:45-07:00" level=info msg="generated new device id: 392080ce2a6e215a94d86d6fe430c295b106d0a2" Jul 11 03:09:45 volumio-2023 go-librespot[4775]: time="2024-07-11T03:09:45-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:45 volumio-2023 go-librespot[4775]: time="2024-07-11T03:09:45-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:45 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:45 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:47 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:47 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:48 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:09:48 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:48 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jul 11 03:09:48 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:48 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:48 volumio-2023 go-librespot[4783]: Librespot-go daemon starting... Jul 11 03:09:48 volumio-2023 go-librespot[4783]: time="2024-07-11T03:09:48-07:00" level=info msg="generated new device id: 7654835e8c3cff7b8854d7c292d237892e84066f" Jul 11 03:09:48 volumio-2023 go-librespot[4783]: time="2024-07-11T03:09:48-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:48 volumio-2023 go-librespot[4783]: time="2024-07-11T03:09:48-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:48 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:48 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:50 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Jul 11 03:09:50 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:50 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:52 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:52 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jul 11 03:09:52 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:52 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:52 volumio-2023 go-librespot[4790]: Librespot-go daemon starting... Jul 11 03:09:52 volumio-2023 go-librespot[4790]: time="2024-07-11T03:09:52-07:00" level=info msg="generated new device id: b5385629e1e255a7ba84fb75acab80c782012dc0" Jul 11 03:09:52 volumio-2023 go-librespot[4790]: time="2024-07-11T03:09:52-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:52 volumio-2023 go-librespot[4790]: time="2024-07-11T03:09:52-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:52 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:52 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:53 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:09:53 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:53 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:55 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:55 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jul 11 03:09:55 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:55 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:55 volumio-2023 go-librespot[4797]: Librespot-go daemon starting... Jul 11 03:09:55 volumio-2023 go-librespot[4797]: time="2024-07-11T03:09:55-07:00" level=info msg="generated new device id: d21b7cedb40f630cc4e9686c1ed96f3acaed520c" Jul 11 03:09:55 volumio-2023 go-librespot[4797]: time="2024-07-11T03:09:55-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:55 volumio-2023 go-librespot[4797]: time="2024-07-11T03:09:55-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:55 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:55 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:09:56 volumio-2023 wpa_supplicant[775]: wlan0: Associated with 8c:61:a3:38:7b:61 Jul 11 03:09:56 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:61:a3:38:7b:61 completed [id=0 id_str=] Jul 11 03:09:56 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 11 03:09:56 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: soliciting an IPv6 router Jul 11 03:09:56 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:56 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:09:56 volumio-2023 dhcpcd[787]: wlan0: rebinding lease of 10.0.0.26 Jul 11 03:09:57 volumio-2023 dhcpcd[787]: wlan0: probing address 10.0.0.26/24 Jul 11 03:09:58 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:09:58 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jul 11 03:09:58 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:09:58 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:09:58 volumio-2023 go-librespot[4816]: Librespot-go daemon starting... Jul 11 03:09:58 volumio-2023 go-librespot[4816]: time="2024-07-11T03:09:58-07:00" level=info msg="generated new device id: b8f5b567ddbf82ce29c39aa9d816bf1615d63584" Jul 11 03:09:58 volumio-2023 go-librespot[4816]: time="2024-07-11T03:09:58-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:09:58 volumio-2023 go-librespot[4816]: time="2024-07-11T03:09:58-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:09:58 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:09:58 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:09:59 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:09:59 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:01 volumio-2023 dhcpcd[787]: wlan0: leased 10.0.0.26 for 172800 seconds Jul 11 03:10:01 volumio-2023 avahi-daemon[512]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.0.0.26. Jul 11 03:10:01 volumio-2023 dhcpcd[787]: wlan0: adding route to 10.0.0.0/24 Jul 11 03:10:01 volumio-2023 avahi-daemon[512]: New relevant interface wlan0.IPv4 for mDNS. Jul 11 03:10:01 volumio-2023 dhcpcd[787]: wlan0: adding default route via 10.0.0.1 Jul 11 03:10:01 volumio-2023 avahi-daemon[512]: Registering new address record for 10.0.0.26 on wlan0.IPv4. Jul 11 03:10:01 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:01 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jul 11 03:10:01 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:01 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:01 volumio-2023 go-librespot[4845]: Librespot-go daemon starting... Jul 11 03:10:01 volumio-2023 go-librespot[4845]: time="2024-07-11T03:10:01-07:00" level=info msg="generated new device id: d6ce68287679156ad5e6a92b5bb1eea2c8bb622c" Jul 11 03:10:01 volumio-2023 go-librespot[4845]: time="2024-07-11T03:10:01-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:02 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:02 volumio-2023 go-librespot[4845]: time="2024-07-11T03:10:02-07:00" level=debug msg="new websocket client" Jul 11 03:10:02 volumio-2023 volumio[1954]: info: Connection to go-librespot Websocket established Jul 11 03:10:03 volumio-2023 ntpd[682]: Listen normally on 10 wlan0 10.0.0.26:123 Jul 11 03:10:03 volumio-2023 ntpd[682]: new interface(s) found: waking up resolver Jul 11 03:10:05 volumio-2023 volumio[1954]: info: Getting Spotify volume Jul 11 03:10:05 volumio-2023 volumio[1954]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jul 11 03:10:05 volumio-2023 volumio[1954]: info: CoreCommandRouter::volumioGetState Jul 11 03:10:11 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-DISCONNECTED bssid=8c:61:a3:38:7b:61 reason=8 Jul 11 03:10:11 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:11 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jul 11 03:10:11 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=CA Jul 11 03:10:11 volumio-2023 avahi-daemon[512]: Withdrawing address record for 10.0.0.26 on wlan0. Jul 11 03:10:11 volumio-2023 avahi-daemon[512]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 10.0.0.26. Jul 11 03:10:11 volumio-2023 avahi-daemon[512]: Interface wlan0.IPv4 no longer relevant for mDNS. Jul 11 03:10:11 volumio-2023 dhcpcd[787]: wlan0: deleting route to 10.0.0.0/24 Jul 11 03:10:11 volumio-2023 dhcpcd[787]: wlan0: deleting default route via 10.0.0.1 Jul 11 03:10:11 volumio-2023 volumio[1954]: info: Discovery: A device disappeared from network Jul 11 03:10:11 volumio-2023 volumio[1954]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'pushMultiroomDevices' of null Jul 11 03:10:13 volumio-2023 ntpd[682]: Deleting interface #10 wlan0, 10.0.0.26#123, interface stats: received=0, sent=6, dropped=0, active_time=10 secs Jul 11 03:10:13 volumio-2023 ntpd[682]: 217.180.209.214 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 ntpd[682]: 131.153.171.22 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 ntpd[682]: 199.182.221.110 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 ntpd[682]: 162.159.200.123 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 ntpd[682]: 162.159.200.1 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 ntpd[682]: 103.144.177.88 local addr 10.0.0.26 -> Jul 11 03:10:13 volumio-2023 go-librespot[4845]: time="2024-07-11T03:10:13-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:14 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:14 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:14 volumio-2023 volumio[1954]: (node:1954) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 11 03:10:14 volumio-2023 volumio[1954]: at connResetException (internal/errors.js:607:14) Jul 11 03:10:14 volumio-2023 volumio[1954]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 11 03:10:14 volumio-2023 volumio[1954]: at Socket.emit (events.js:327:22) Jul 11 03:10:14 volumio-2023 volumio[1954]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 11 03:10:14 volumio-2023 volumio[1954]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 11 03:10:14 volumio-2023 volumio[1954]: (node:1954) 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: 7) Jul 11 03:10:14 volumio-2023 volumio[1954]: info: Connection to go-librespot Websocket closed Jul 11 03:10:14 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:10:15 volumio-2023 ntpd[682]: Soliciting pool server 174.142.148.226 Jul 11 03:10:16 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Jul 11 03:10:17 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:17 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:17 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:17 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jul 11 03:10:17 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:17 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:17 volumio-2023 go-librespot[4902]: Librespot-go daemon starting... Jul 11 03:10:17 volumio-2023 go-librespot[4902]: time="2024-07-11T03:10:17-07:00" level=info msg="generated new device id: bdb1bbd68d2839c2f03921a97c099adc1e3c4aae" Jul 11 03:10:17 volumio-2023 go-librespot[4902]: time="2024-07-11T03:10:17-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:17 volumio-2023 go-librespot[4902]: time="2024-07-11T03:10:17-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:17 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:17 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:17 volumio-2023 ntpd[682]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jul 11 03:10:19 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:10:19 volumio-2023 volumio[1954]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008 Jul 11 03:10:20 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:20 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:20 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:20 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jul 11 03:10:20 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:20 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:20 volumio-2023 go-librespot[4911]: Librespot-go daemon starting... Jul 11 03:10:20 volumio-2023 go-librespot[4911]: time="2024-07-11T03:10:20-07:00" level=info msg="generated new device id: f421f0034b55743f69cd7b64cdd00bd569536386" Jul 11 03:10:20 volumio-2023 go-librespot[4911]: time="2024-07-11T03:10:20-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:20 volumio-2023 go-librespot[4911]: time="2024-07-11T03:10:20-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:20 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:20 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:22 volumio-2023 wpa_supplicant[775]: wlan0: Associated with 8c:61:a3:38:7b:60 Jul 11 03:10:22 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:61:a3:38:7b:60 completed [id=0 id_str=] Jul 11 03:10:22 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 11 03:10:22 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:22 volumio-2023 dhcpcd[787]: wlan0: soliciting an IPv6 router Jul 11 03:10:23 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:23 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:23 volumio-2023 dhcpcd[787]: wlan0: rebinding lease of 10.0.0.26 Jul 11 03:10:23 volumio-2023 dhcpcd[787]: wlan0: probing address 10.0.0.26/24 Jul 11 03:10:23 volumio-2023 ntpd[682]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jul 11 03:10:23 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:23 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jul 11 03:10:23 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:23 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:23 volumio-2023 go-librespot[4930]: Librespot-go daemon starting... Jul 11 03:10:23 volumio-2023 go-librespot[4930]: time="2024-07-11T03:10:23-07:00" level=info msg="generated new device id: 047ef97a41c7af63e0968e0ef2cf7fcf33ac3d21" Jul 11 03:10:23 volumio-2023 go-librespot[4930]: time="2024-07-11T03:10:23-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:23 volumio-2023 go-librespot[4930]: time="2024-07-11T03:10:23-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:23 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:23 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:25 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-DISCONNECTED bssid=8c:61:a3:38:7b:60 reason=1 Jul 11 03:10:25 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:25 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jul 11 03:10:25 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=CA Jul 11 03:10:26 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:26 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:26 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:10:26 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:26 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jul 11 03:10:26 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:26 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:26 volumio-2023 go-librespot[4959]: Librespot-go daemon starting... Jul 11 03:10:26 volumio-2023 go-librespot[4959]: time="2024-07-11T03:10:26-07:00" level=info msg="generated new device id: 2a28eac2cde6c4ea3fef33235ea9d31123de2ed2" Jul 11 03:10:26 volumio-2023 go-librespot[4959]: time="2024-07-11T03:10:26-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:26 volumio-2023 go-librespot[4959]: time="2024-07-11T03:10:26-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:26 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:26 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:28 volumio-2023 wpa_supplicant[775]: wlan0: Associated with 8c:61:a3:38:7b:60 Jul 11 03:10:28 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:61:a3:38:7b:60 completed [id=0 id_str=] Jul 11 03:10:28 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 11 03:10:28 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:28 volumio-2023 dhcpcd[787]: wlan0: soliciting an IPv6 router Jul 11 03:10:29 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:29 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:29 volumio-2023 dhcpcd[787]: wlan0: rebinding lease of 10.0.0.26 Jul 11 03:10:30 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:30 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jul 11 03:10:30 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:30 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:30 volumio-2023 go-librespot[4978]: Librespot-go daemon starting... Jul 11 03:10:30 volumio-2023 go-librespot[4978]: time="2024-07-11T03:10:30-07:00" level=info msg="generated new device id: 9c900b36ab0961d85e42c05bd2aecb96e7d7fe83" Jul 11 03:10:30 volumio-2023 go-librespot[4978]: time="2024-07-11T03:10:30-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:30 volumio-2023 go-librespot[4978]: time="2024-07-11T03:10:30-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:30 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:30 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:32 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:32 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:33 volumio-2023 dhcpcd[787]: wlan0: probing address 10.0.0.26/24 Jul 11 03:10:33 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:33 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jul 11 03:10:33 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:33 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:33 volumio-2023 go-librespot[4986]: Librespot-go daemon starting... Jul 11 03:10:33 volumio-2023 go-librespot[4986]: time="2024-07-11T03:10:33-07:00" level=info msg="generated new device id: 7dba8ad0d858cf30fc4af5362b8a87665de20ec8" Jul 11 03:10:33 volumio-2023 go-librespot[4986]: time="2024-07-11T03:10:33-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:33 volumio-2023 go-librespot[4986]: time="2024-07-11T03:10:33-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:33 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:33 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:35 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:35 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:36 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:36 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Jul 11 03:10:36 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:36 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:36 volumio-2023 go-librespot[5036]: Librespot-go daemon starting... Jul 11 03:10:36 volumio-2023 go-librespot[5036]: time="2024-07-11T03:10:36-07:00" level=info msg="generated new device id: a66e6d0d0a734aedd0e3c167f8832fd535841ed1" Jul 11 03:10:36 volumio-2023 go-librespot[5036]: time="2024-07-11T03:10:36-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:36 volumio-2023 go-librespot[5036]: time="2024-07-11T03:10:36-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:36 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:36 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:38 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:38 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:38 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-DISCONNECTED bssid=8c:61:a3:38:7b:60 reason=3 Jul 11 03:10:38 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:38 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jul 11 03:10:38 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=CA Jul 11 03:10:38 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:10:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Jul 11 03:10:39 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:39 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:39 volumio-2023 go-librespot[5063]: Librespot-go daemon starting... Jul 11 03:10:39 volumio-2023 go-librespot[5063]: time="2024-07-11T03:10:39-07:00" level=info msg="generated new device id: d62f429bbb7757ee48dc86319fdbeba493be3dec" Jul 11 03:10:39 volumio-2023 go-librespot[5063]: time="2024-07-11T03:10:39-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:39 volumio-2023 go-librespot[5063]: time="2024-07-11T03:10:39-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:39 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:41 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:41 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: Associated with 8c:61:a3:38:7b:60 Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:61:a3:38:7b:60 completed [id=0 id_str=] Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: rebinding lease of 10.0.0.26 Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: probing address 10.0.0.26/24 Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-DISCONNECTED bssid=8c:61:a3:38:7b:60 reason=2 Jul 11 03:10:41 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=CA Jul 11 03:10:41 volumio-2023 wpa_supplicant[775]: wlan0: Trying to associate with SSID 'HonMoLiu' Jul 11 03:10:43 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:43 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Jul 11 03:10:43 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:43 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:43 volumio-2023 go-librespot[5102]: Librespot-go daemon starting... Jul 11 03:10:43 volumio-2023 go-librespot[5102]: time="2024-07-11T03:10:43-07:00" level=info msg="generated new device id: 5b9ea18ba0894d7392bc98014a078e5c2b08f4bc" Jul 11 03:10:43 volumio-2023 go-librespot[5102]: time="2024-07-11T03:10:43-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:43 volumio-2023 go-librespot[5102]: time="2024-07-11T03:10:43-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:43 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:43 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:44 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:44 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:44 volumio-2023 wpa_supplicant[775]: wlan0: Associated with 8c:61:a3:38:7b:61 Jul 11 03:10:44 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:61:a3:38:7b:61 completed [id=0 id_str=] Jul 11 03:10:44 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 11 03:10:44 volumio-2023 wpa_supplicant[775]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: carrier lost Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: carrier acquired Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: IAID 32:2e:e0:7e Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: rebinding lease of 10.0.0.26 Jul 11 03:10:44 volumio-2023 dhcpcd[787]: wlan0: probing address 10.0.0.26/24 Jul 11 03:10:45 volumio-2023 dhcpcd[787]: wlan0: soliciting an IPv6 router Jul 11 03:10:46 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:46 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Jul 11 03:10:46 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:46 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:46 volumio-2023 go-librespot[5121]: Librespot-go daemon starting... Jul 11 03:10:46 volumio-2023 go-librespot[5121]: time="2024-07-11T03:10:46-07:00" level=info msg="generated new device id: f0ad9fdb1763cc353e9263a50a05dcc369082ccb" Jul 11 03:10:46 volumio-2023 go-librespot[5121]: time="2024-07-11T03:10:46-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:46 volumio-2023 go-librespot[5121]: time="2024-07-11T03:10:46-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jul 11 03:10:46 volumio-2023 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 03:10:46 volumio-2023 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 03:10:47 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:47 volumio-2023 volumio[1954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 03:10:49 volumio-2023 dhcpcd[787]: wlan0: leased 10.0.0.26 for 172800 seconds Jul 11 03:10:49 volumio-2023 avahi-daemon[512]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.0.0.26. Jul 11 03:10:49 volumio-2023 dhcpcd[787]: wlan0: adding route to 10.0.0.0/24 Jul 11 03:10:49 volumio-2023 dhcpcd[787]: wlan0: adding default route via 10.0.0.1 Jul 11 03:10:49 volumio-2023 avahi-daemon[512]: New relevant interface wlan0.IPv4 for mDNS. Jul 11 03:10:49 volumio-2023 avahi-daemon[512]: Registering new address record for 10.0.0.26 on wlan0.IPv4. Jul 11 03:10:49 volumio-2023 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 11 03:10:49 volumio-2023 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Jul 11 03:10:49 volumio-2023 systemd[1]: Stopped go-librespot Daemon. Jul 11 03:10:49 volumio-2023 systemd[1]: Started go-librespot Daemon. Jul 11 03:10:49 volumio-2023 go-librespot[5151]: Librespot-go daemon starting... Jul 11 03:10:49 volumio-2023 go-librespot[5151]: time="2024-07-11T03:10:49-07:00" level=info msg="generated new device id: 10b110c4bfd6c904abb2c79cbe88ddb441c2616c" Jul 11 03:10:49 volumio-2023 go-librespot[5151]: time="2024-07-11T03:10:49-07:00" level=debug msg="stored credentials found for bxpkldhp2p7ecszctg4gtfvh5" Jul 11 03:10:50 volumio-2023 volumio[1954]: info: Initializing connection to go-librespot Websocket Jul 11 03:10:50 volumio-2023 volumio[1954]: info: Connection to go-librespot Websocket established Jul 11 03:10:50 volumio-2023 go-librespot[5151]: time="2024-07-11T03:10:50-07:00" level=debug msg="new websocket client" Jul 11 03:10:50 volumio-2023 volumio[1954]: info: Discovery: adding 9a7463e8-6508-4875-80f8-3ca6f8172679 Jul 11 03:10:50 volumio-2023 volumio[1954]: info: Discovery: Found device Volumio-2023 Jul 11 03:10:50 volumio-2023 volumio[1954]: info: CoreCommandRouter::volumioGetState Jul 11 03:10:50 volumio-2023 volumio[1954]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 03:10:50 volumio-2023 volumio[1954]: TypeError: Cannot read property 'pushMultiroomDevices' of null Jul 11 03:10:50 volumio-2023 volumio[1954]: at /volumio/app/index.js:1242:32 Jul 11 03:10:50 volumio-2023 volumio[1954]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Jul 11 03:10:50 volumio-2023 volumio[1954]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Jul 11 03:10:50 volumio-2023 volumio[1954]: at CoreCommandRouter.pushMultiroomDevices (/volumio/app/index.js:1240:13) Jul 11 03:10:50 volumio-2023 volumio[1954]: at ControllerVolumioDiscovery.pushMultiRoomStatus (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:339:22) Jul 11 03:10:50 volumio-2023 volumio[1954]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:333:8) Jul 11 03:10:50 volumio-2023 volumio[1954]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Jul 11 03:10:50 volumio-2023 volumio[1954]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Jul 11 03:10:50 volumio-2023 volumio[1954]: at Browser.emit (events.js:315:20) Jul 11 03:10:50 volumio-2023 volumio[1954]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Jul 11 03:10:50 volumio-2023 volumio[1954]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Jul 11 03:10:50 volumio-2023 volumio[1954]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Jul 11 03:10:50 volumio-2023 volumio[1954]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Jul 11 03:10:50 volumio-2023 volumio[1954]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Jul 11 03:10:50 volumio-2023 volumio[1954]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Jul 11 03:10:50 volumio-2023 volumio[1954]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Jul 11 03:10:50 volumio-2023 volumio[1954]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 03:10:50 volumio-2023 ntpd[682]: Listen normally on 11 wlan0 10.0.0.26:123 Jul 11 03:10:50 volumio-2023 ntpd[682]: new interface(s) found: waking up resolver Jul 11 03:10:51 volumio-2023 sudo[5172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-11 03:09 Jul 11 03:10:51 volumio-2023 sudo[5172]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"