-- 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"