-- Logs begin at Thu 2019-02-14 03:11:59 MST, end at Tue 2024-08-27 18:54:31 MST. -- Aug 27 18:53:00 volumio-vick wpa_supplicant[908]: wlan0: Associated with 58:96:30:a2:de:01 Aug 27 18:53:00 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-CONNECTED - Connection to 58:96:30:a2:de:01 completed [id=0 id_str=] Aug 27 18:53:00 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 18:53:00 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Aug 27 18:53:00 volumio-vick dhcpcd[724]: wlan0: carrier acquired Aug 27 18:53:00 volumio-vick dhcpcd[724]: wlan0: IAID 32:b3:87:81 Aug 27 18:53:00 volumio-vick dhcpcd[724]: wlan0: rebinding lease of 192.168.0.69 Aug 27 18:53:00 volumio-vick dhcpcd[724]: wlan0: probing address 192.168.0.69/24 Aug 27 18:53:00 volumio-vick dhcpcd[724]: wlan0: soliciting an IPv6 router Aug 27 18:53:02 volumio-vick volumio[995]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008 Aug 27 18:53:04 volumio-vick go-librespot[5019]: time="2024-08-27T18:53:04-07:00" level=debug msg="renewing login5 access token" Aug 27 18:53:05 volumio-vick dhcpcd[724]: wlan0: leased 192.168.0.69 for 172800 seconds Aug 27 18:53:05 volumio-vick avahi-daemon[649]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.69. Aug 27 18:53:05 volumio-vick avahi-daemon[649]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 18:53:05 volumio-vick avahi-daemon[649]: Registering new address record for 192.168.0.69 on wlan0.IPv4. Aug 27 18:53:05 volumio-vick dhcpcd[724]: wlan0: adding route to 192.168.0.0/24 Aug 27 18:53:05 volumio-vick dhcpcd[724]: wlan0: adding default route via 192.168.0.1 Aug 27 18:53:06 volumio-vick ntpd[793]: Listen normally on 6 wlan0 192.168.0.69:123 Aug 27 18:53:06 volumio-vick ntpd[793]: new interface(s) found: waking up resolver Aug 27 18:53:06 volumio-vick volumio[995]: verbose: New Socket.io Connection to 192.168.0.69 from 192.168.0.123 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 18:53:06 volumio-vick volumio[995]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 18:53:06 volumio-vick volumio[995]: info: Received Get System Info Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:53:06 volumio-vick volumio[995]: info: Discovery: Getting this device information Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:53:06 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:06 volumio-vick volumio[995]: info: Listing playlists Aug 27 18:53:08 volumio-vick ntpd[793]: Soliciting pool server 104.152.220.10 Aug 27 18:53:09 volumio-vick volumio[995]: info: Executing endpoint metavolumio Aug 27 18:53:09 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 18:53:10 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-DISCONNECTED bssid=58:96:30:a2:de:01 reason=1 Aug 27 18:53:10 volumio-vick dhcpcd[724]: wlan0: carrier lost Aug 27 18:53:10 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Aug 27 18:53:10 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Aug 27 18:53:10 volumio-vick avahi-daemon[649]: Withdrawing address record for 192.168.0.69 on wlan0. Aug 27 18:53:10 volumio-vick avahi-daemon[649]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.69. Aug 27 18:53:10 volumio-vick avahi-daemon[649]: Interface wlan0.IPv4 no longer relevant for mDNS. Aug 27 18:53:10 volumio-vick dhcpcd[724]: wlan0: deleting route to 192.168.0.0/24 Aug 27 18:53:10 volumio-vick dhcpcd[724]: wlan0: deleting default route via 192.168.0.1 Aug 27 18:53:10 volumio-vick volumio[995]: info: Discovery: A device disappeared from network Aug 27 18:53:11 volumio-vick ntpd[793]: Deleting interface #6 wlan0, 192.168.0.69#123, interface stats: received=0, sent=12, dropped=5, active_time=5 secs Aug 27 18:53:11 volumio-vick ntpd[793]: 66.205.249.28 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 212.227.240.160 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 45.33.53.84 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 64.142.54.12 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 23.168.136.132 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 74.208.199.139 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 74.208.117.38 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 74.50.98.131 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 74.6.168.72 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 50.205.57.38 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 155.138.194.125 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 208.67.72.43 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 142.202.190.19 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 23.168.24.210 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 51.81.226.229 local addr 192.168.0.69 -> Aug 27 18:53:11 volumio-vick ntpd[793]: 143.42.229.154 local addr 192.168.0.69 -> Aug 27 18:53:12 volumio-vick ntpd[793]: Soliciting pool server 2603:c020:0:8369::bad:beef Aug 27 18:53:13 volumio-vick wpa_supplicant[908]: wlan0: Trying to associate with SSID 'vickHome-5G' Aug 27 18:53:13 volumio-vick go-librespot[5019]: time="2024-08-27T18:53:13-07:00" level=error msg="did not receive last pong ack from accesspoint, 358s passed" Aug 27 18:53:13 volumio-vick go-librespot[5019]: panic: runtime error: invalid memory address or nil pointer dereference Aug 27 18:53:13 volumio-vick go-librespot[5019]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x48d52c] Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 46 gp=0x1c039e8 m=4 mp=0x1c47088 [running]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: panic({0x5ea978, 0xa60098}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:779 +0x12c fp=0x1c57f14 sp=0x1c57ec0 pc=0x58364 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.panicmem(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:261 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.sigpanic() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/signal_unix.go:881 +0x39c fp=0x1c57f44 sp=0x1c57f14 pc=0x74350 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x1e5a328) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:317 +0x24c fp=0x1c57fe4 sp=0x1c57f48 pc=0x48d52c Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/ap.NewAccesspoint.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x28 fp=0x1c57fec sp=0x1c57fe4 pc=0x48b70c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c57fec sp=0x1c57fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/ap.NewAccesspoint in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x188 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 1 gp=0x1c02128 m=nil [select, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e29d0c sp=0x1e29cf8 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1e29e0c, 0x1dc9dd8, 0x0, 0x0, 0x2, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1e29dac sp=0x1e29d0c pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/zeroconf.(*Zeroconf).Serve(0x1e200a0, 0x1e29e88) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:268 +0x228 fp=0x1e29e50 sp=0x1e29dac pc=0x528ad8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).withAppPlayer(0x1cae360, 0x1dee0c0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:297 +0x4b0 fp=0x1e29ec0 sp=0x1e29e50 pc=0x578904 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).withCredentials(0x1cae360, {0x5f2fc8, 0x1ca6500}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:171 +0x3d4 fp=0x1e29f1c sp=0x1e29ec0 pc=0x577fdc Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).SpotifyToken(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:131 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.main() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:466 +0x530 fp=0x1e29fa8 sp=0x1e29f1c pc=0x579f24 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.main() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:271 +0x2fc fp=0x1e29fec sp=0x1e29fa8 pc=0x5c29c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e29fec sp=0x1e29fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 2 gp=0x1c027e8 m=nil [force gc (idle), 3 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f740, 0xaa84c0, 0x11, 0xa, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c42fd4 sp=0x1c42fc0 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goparkunlock(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.forcegchelper() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:326 +0xe4 fp=0x1c42fec sp=0x1c42fd4 pc=0x5c668 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c42fec sp=0x1c42fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.init.5 in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:314 +0x1c Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 18 gp=0x1c84248 m=nil [GC sweep wait]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f740, 0xaa8a10, 0xc, 0x9, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c3e7c4 sp=0x1c3e7b0 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goparkunlock(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.bgsweep(0x1c6a000) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcsweep.go:318 +0x11c fp=0x1c3e7e4 sp=0x1c3e7c4 pc=0x4506c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcenable.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x28 fp=0x1c3e7ec sp=0x1c3e7e4 pc=0x3518c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c3e7ec sp=0x1c3e7ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcenable in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x74 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 19 gp=0x1c84368 m=nil [GC scavenge wait]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f740, 0xaa9020, 0xd, 0xa, 0x2) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c3efb4 sp=0x1c3efa0 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goparkunlock(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.(*scavengerState).park(0xaa9020) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:425 +0x68 fp=0x1c3efc8 sp=0x1c3efb4 pc=0x4238c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.bgscavenge(0x1c6a000) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:658 +0x60 fp=0x1c3efe4 sp=0x1c3efc8 pc=0x42ac4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcenable.gowrap2() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0x28 fp=0x1c3efec sp=0x1c3efe4 pc=0x35138 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c3efec sp=0x1c3efec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcenable in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0xbc Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 20 gp=0x1c846c8 m=nil [finalizer wait, 111 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5ec, 0xad3bac, 0x10, 0xa, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c3f78c sp=0x1c3f778 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.runfinq() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:194 +0x110 fp=0x1c3f7ec sp=0x1c3f78c pc=0x33f78 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c3f7ec sp=0x1c3f7ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.createfing in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:164 +0x5c Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 21 gp=0x1c84ea8 m=nil [IO wait, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f730, 0xb5683f08, 0x2, 0x2, 0x5) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c425dc sp=0x1c425c8 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.netpollblock(0xb5683ef8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c425f4 sp=0x1c425dc pc=0x540f0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.runtime_pollWait(0xb5683ef8, 0x72) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c42608 sp=0x1c425f4 pc=0x8eba8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).wait(0x1ca2fb8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c4261c sp=0x1c42608 pc=0x108108 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).waitRead(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*FD).Accept(0x1ca2fa0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x1c42664 sp=0x1c4261c pc=0x10c974 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*netFD).accept(0x1ca2fa0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x1c426cc sp=0x1c42664 pc=0x2a24f4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*TCPListener).accept(0x1cbc3a8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x1c426e4 sp=0x1c426cc pc=0x2ba5f4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*TCPListener).Accept(0x1cbc3a8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x1c42700 sp=0x1c426e4 pc=0x2b9660 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*onceCloseListener).Accept(0x1d222a0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: :1 +0x34 fp=0x1c42718 sp=0x1c42700 pc=0x45e904 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*Server).Serve(0x1d1e0a8, {0x724fbc, 0x1cbc3a8}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x1c427b0 sp=0x1c42718 pc=0x43cfc0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.Serve(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*ApiServer).serve(0x1c95a00) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:470 +0x5ec fp=0x1c427e4 sp=0x1c427b0 pc=0x5706a4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.NewApiServer.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x28 fp=0x1c427ec sp=0x1c427e4 pc=0x56fd78 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c427ec sp=0x1c427ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by main.NewApiServer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x224 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 10 gp=0x1c84fc8 m=nil [select]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e25e88 sp=0x1e25e74 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1e25fd4, 0x1e25f50, 0x0, 0x0, 0x2, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1e25f28 sp=0x1e25e88 pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/dealer.(*Dealer).pingTicker(0x1caab48) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:107 +0x8c fp=0x1e25fe4 sp=0x1e25f28 pc=0x4b8428 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/dealer.NewDealer.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x1e25fec sp=0x1e25fe4 pc=0x4b7ef8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e25fec sp=0x1e25fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/dealer.NewDealer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x180 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 11 gp=0x1c850e8 m=nil [select, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c4367c sp=0x1c43668 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1c437cc, 0x1c43744, 0x0, 0x0, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c4371c sp=0x1c4367c pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/player.(*Player).manageLoop(0x1e32780) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/player/player.go:109 +0x1e0 fp=0x1c437e4 sp=0x1c4371c pc=0x4a7164 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/player.NewPlayer.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x28 fp=0x1c437ec sp=0x1c437e4 pc=0x4a6e98 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c437ec sp=0x1c437ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/player.NewPlayer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x1e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 28 gp=0x1c85448 m=nil [IO wait, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f730, 0xb5683dc8, 0x2, 0x2, 0x5) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c548a4 sp=0x1c54890 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.netpollblock(0xb5683db8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c548bc sp=0x1c548a4 pc=0x540f0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.runtime_pollWait(0xb5683db8, 0x72) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c548d0 sp=0x1c548bc pc=0x8eba8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).wait(0x1ca32d8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c548e4 sp=0x1c548d0 pc=0x108108 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).waitRead(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*FD).Read(0x1ca32c0, {0x1df4000, 0x1000, 0x1000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1c5492c sp=0x1c548e4 pc=0x1092f4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*netFD).Read(0x1ca32c0, {0x1df4000, 0x1000, 0x1000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1c54958 sp=0x1c5492c pc=0x2a0600 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*conn).Read(0x1c907b0, {0x1df4000, 0x1000, 0x1000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1c54984 sp=0x1c54958 pc=0x2b07e0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*TCPConn).Read(0x1c907b0, {0x1df4000, 0x1000, 0x1000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: :1 +0x44 fp=0x1c549a4 sp=0x1c54984 pc=0x2c3a34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: io.(*multiReader).Read(0x1ca66e0, {0x1df4000, 0x1000, 0x1000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/multi.go:26 +0xb4 fp=0x1c549d0 sp=0x1c549a4 pc=0x103318 Aug 27 18:53:13 volumio-vick go-librespot[5019]: bufio.(*Reader).fill(0x1cae630) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x1c549f4 sp=0x1c549d0 pc=0x15a4b8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: bufio.(*Reader).ReadByte(0x1cae630) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x28 fp=0x1c54a00 sp=0x1c549f4 pc=0x15ad3c Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.readFrameHeader(0x1cae630, {0x1daa678, 0x8, 0x8}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x1c54a40 sp=0x1c54a00 pc=0x4771d0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x1daa648, {0x7253c8, 0xad3b20}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x1c54b00 sp=0x1c54a40 pc=0x479e34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).readLoop(0x1daa648, {0x7253c8, 0xad3b20}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x1c54bc4 sp=0x1c54b00 pc=0x47991c Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).reader(0x1daa648, {0x7253c8, 0xad3b20}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x1c54c50 sp=0x1c54bc4 pc=0x47ab30 Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).Reader(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).Read(0x1daa648, {0x7253c8, 0xad3b20}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x1c54c78 sp=0x1c54c50 pc=0x479200 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*ApiServer).serve.func14({0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:450 +0x22c fp=0x1c54cd0 sp=0x1c54c78 pc=0x570ae0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.HandlerFunc.ServeHTTP(0x1d1c140, {0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x1c54ce0 sp=0x1c54cd0 pc=0x4395a4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*ServeMux).ServeHTTP(0x1d14000, {0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2683 +0x208 fp=0x1c54d1c sp=0x1c54ce0 pc=0x43b404 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*ApiServer).serve.(*ApiServer).allowOriginMiddleware.func15({0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:273 +0xa4 fp=0x1c54d40 sp=0x1c54d1c pc=0x57089c Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.HandlerFunc.ServeHTTP(0x1d16120, {0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x1c54d50 sp=0x1c54d40 pc=0x4395a4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.serverHandler.ServeHTTP({0x1d1e0a8}, {0x7250f0, 0x1cabcc8}, 0x1cabae8) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3137 +0xe0 fp=0x1c54d6c sp=0x1c54d50 pc=0x43cb94 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*conn).serve(0x1cdb080, {0x7253e8, 0x1d24138}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2039 +0x61c fp=0x1c54fdc sp=0x1c54d6c pc=0x437de4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*Server).Serve.gowrap3() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x38 fp=0x1c54fec sp=0x1c54fdc pc=0x43d438 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c54fec sp=0x1c54fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by net/http.(*Server).Serve in goroutine 21 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x468 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 30 gp=0x1c85688 m=nil [select, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c40ea8 sp=0x1c40e94 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1c40fa4, 0x1c40f6c, 0x0, 0x0, 0x5, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c40f48 sp=0x1c40ea8 pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x1daa648) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x1c40fe4 sp=0x1c40f48 pc=0x47407c Aug 27 18:53:13 volumio-vick go-librespot[5019]: nhooyr.io/websocket.newConn.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x1c40fec sp=0x1c40fe4 pc=0x473c70 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c40fec sp=0x1c40fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by nhooyr.io/websocket.newConn in goroutine 28 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 37 gp=0x1e42248 m=nil [GC worker (idle), 32 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5fc, 0x1cba828, 0x1a, 0xa, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c40790 sp=0x1c4077c pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcBgMarkWorker() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x1c407ec sp=0x1c40790 pc=0x37db4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c407ec sp=0x1c407ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 31 gp=0x1c857a8 m=nil [GC worker (idle)]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5fc, 0x1d56a98, 0x1a, 0xa, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c41790 sp=0x1c4177c pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcBgMarkWorker() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x1c417ec sp=0x1c41790 pc=0x37db4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c417ec sp=0x1c417ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 50 gp=0x1d08248 m=nil [GC worker (idle), 32 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5fc, 0x1d56ab0, 0x1a, 0xa, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1ef0790 sp=0x1ef077c pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcBgMarkWorker() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x1ef07ec sp=0x1ef0790 pc=0x37db4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1ef07ec sp=0x1ef07ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 51 gp=0x1d08368 m=nil [GC worker (idle), 14 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5fc, 0x203a3a8, 0x1a, 0xa, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1ef0f90 sp=0x1ef0f7c pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gcBgMarkWorker() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x1ef0fec sp=0x1ef0f90 pc=0x37db4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1ef0fec sp=0x1ef0fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 38 gp=0x1c847e8 m=nil [IO wait]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f730, 0xb5683be8, 0x2, 0x2, 0x5) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e26e84 sp=0x1e26e70 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.netpollblock(0xb5683bd8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1e26e9c sp=0x1e26e84 pc=0x540f0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.runtime_pollWait(0xb5683bd8, 0x72) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1e26eb0 sp=0x1e26e9c pc=0x8eba8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).wait(0x1e20248, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1e26ec4 sp=0x1e26eb0 pc=0x108108 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).waitRead(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*FD).RawRead(0x1e20230, 0x1f0a330) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x1e26ef0 sp=0x1e26ec4 pc=0x10d578 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*rawConn).Read(0x20542c8, 0x1f0a330) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x1e26f10 sp=0x1e26ef0 pc=0x2b4a1c Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x1e2c1f0, 0x1f0a300, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x1e26f40 sp=0x1e26f10 pc=0x4c965c Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x1e2e0f8, {0x1ea0000, 0x10000, 0x10000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv4/payload_cmsg.go:32 +0x44c fp=0x1e26f9c sp=0x1e26f40 pc=0x4cd644 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/grandcat/zeroconf.(*Server).recv4(0x20124c0, 0x1e2e0f0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xec fp=0x1e26fe0 sp=0x1e26f9c pc=0x523ed4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x1e26fec sp=0x1e26fe0 pc=0x523b8c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e26fec sp=0x1e26fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 52 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 39 gp=0x1c84908 m=nil [IO wait, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f730, 0xb5683b48, 0x2, 0x2, 0x5) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e8d65c sp=0x1e8d648 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.netpollblock(0xb5683b38, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1e8d674 sp=0x1e8d65c pc=0x540f0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.runtime_pollWait(0xb5683b38, 0x72) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1e8d688 sp=0x1e8d674 pc=0x8eba8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).wait(0x1e20298, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1e8d69c sp=0x1e8d688 pc=0x108108 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).waitRead(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*FD).RawRead(0x1e20280, 0x1e9e030) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x1e8d6c8 sp=0x1e8d69c pc=0x10d578 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*rawConn).Read(0x20542f0, 0x1e9e030) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x1e8d6e8 sp=0x1e8d6c8 pc=0x2b4a1c Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x1e2c200, 0x1e9e000, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x1e8d718 sp=0x1e8d6e8 pc=0x4c965c Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Aug 27 18:53:13 volumio-vick go-librespot[5019]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x1e2e128, {0x1e8e000, 0x10000, 0x10000}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv6/payload_cmsg.go:32 +0x2ec fp=0x1e8d79c sp=0x1e8d718 pc=0x4d0fcc Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/grandcat/zeroconf.(*Server).recv6(0x20124c0, 0x1e2e120) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xec fp=0x1e8d7e0 sp=0x1e8d79c pc=0x5240c8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x1e8d7ec sp=0x1e8d7e0 pc=0x523b30 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e8d7ec sp=0x1e8d7ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 52 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 63 gp=0x200c008 m=nil [select]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2074dd8 sp=0x2074dc4 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x2074ecc, 0x2074ea0, 0x0, 0x0, 0x2, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2074e78 sp=0x2074dd8 pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x2074f1c, {0x7248b0, 0x1f18f60}, 0x0, {0x0, 0x0}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x260 fp=0x2074ef4 sp=0x2074e78 pc=0x47ffec Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x2105f64, {0x7248b0, 0x1f18f60}, 0x0, {0x0, 0x0}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x2074f24 sp=0x2074ef4 pc=0x47fa80 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.RetryNotify(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.Retry(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/dealer.(*Dealer).recvLoop(0x1caab48) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:193 +0x558 fp=0x2074fe4 sp=0x2074f24 pc=0x4b8d6c Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x28 fp=0x2074fec sp=0x2074fe4 pc=0x4ba0c4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2074fec sp=0x2074fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1 in goroutine 13 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x60 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 62 gp=0x1d08c68 m=nil [select]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e28db0 sp=0x1e28d9c pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1e28ea4, 0x1e28e78, 0x0, 0x0, 0x2, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1e28e50 sp=0x1e28db0 pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x1e28ef4, {0x7248b0, 0x2128420}, 0x0, {0x0, 0x0}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x260 fp=0x1e28ecc sp=0x1e28e50 pc=0x47ffec Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x1e28f64, {0x7248b0, 0x2128420}, 0x0, {0x0, 0x0}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x1e28efc sp=0x1e28ecc pc=0x47fa80 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.RetryNotify(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Aug 27 18:53:13 volumio-vick go-librespot[5019]: github.com/cenkalti/backoff/v4.Retry(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/ap.(*Accesspoint).recvLoop(0x1e5a328) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:278 +0x38c fp=0x1e28fe4 sp=0x1e28efc pc=0x48cf30 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:229 +0x28 fp=0x1e28fec sp=0x1e28fe4 pc=0x48cb78 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e28fec sp=0x1e28fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 13 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:229 +0x60 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 13 gp=0x1d08d88 m=nil [select, 12 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f774, 0x0, 0x9, 0x3, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1dc585c sp=0x1dc5848 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.selectgo(0x1dc5e34, 0x1dc5a3c, 0x0, 0x0, 0x6, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1dc58fc sp=0x1dc585c pc=0x705e4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*AppPlayer).Run(0x1e202d0, 0x1cad9c0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:430 +0x1fc fp=0x1dc5fe0 sp=0x1dc58fc pc=0x57dda8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).withAppPlayer.gowrap1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x30 fp=0x1dc5fec sp=0x1dc5fe0 pc=0x5792a4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1dc5fec sp=0x1dc5fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by main.(*App).withAppPlayer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x348 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 14 gp=0x1d08ea8 m=nil [chan receive, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5d0, 0x1cac1f0, 0xe, 0x7, 0x2) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c44f48 sp=0x1c44f34 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.chanrecv(0x1cac1c0, 0x1c44fd0, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x1c44f84 sp=0x1c44f48 pc=0x1fdc4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.chanrecv2(0x1cac1c0, 0x1c44fd0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x1c44f98 sp=0x1c44f84 pc=0x1f908 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).withAppPlayer.func1() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:245 +0x54 fp=0x1c44fec sp=0x1c44f98 pc=0x5791d4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c44fec sp=0x1c44fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by main.(*App).withAppPlayer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:242 +0x3d4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 15 gp=0x1d08fc8 m=nil [chan receive, 114 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f5d0, 0x1cac170, 0xe, 0x7, 0x2) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c4573c sp=0x1c45728 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.chanrecv(0x1cac140, 0x1c457e0, 0x1) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x1c45778 sp=0x1c4573c pc=0x1fdc4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.chanrecv2(0x1cac140, 0x1c457e0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x1c4578c sp=0x1c45778 pc=0x1f908 Aug 27 18:53:13 volumio-vick go-librespot[5019]: main.(*App).withAppPlayer.func2() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:261 +0x5c fp=0x1c457ec sp=0x1c4578c pc=0x578de8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c457ec sp=0x1c457ec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by main.(*App).withAppPlayer in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:258 +0x45c Aug 27 18:53:13 volumio-vick go-librespot[5019]: goroutine 16 gp=0x1d09208 m=nil [IO wait, 33 minutes]: Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.gopark(0x68f730, 0xb5683c88, 0x2, 0x2, 0x5) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c45de8 sp=0x1c45dd4 pc=0x5c82c Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.netpollblock(0xb5683c78, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c45e00 sp=0x1c45de8 pc=0x540f0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.runtime_pollWait(0xb5683c78, 0x72) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c45e14 sp=0x1c45e00 pc=0x8eba8 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).wait(0x1e201f8, 0x72, 0x0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c45e28 sp=0x1c45e14 pc=0x108108 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*pollDesc).waitRead(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Aug 27 18:53:13 volumio-vick go-librespot[5019]: internal/poll.(*FD).Accept(0x1e201e0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x1c45e70 sp=0x1c45e28 pc=0x10c974 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*netFD).accept(0x1e201e0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x1c45ed8 sp=0x1c45e70 pc=0x2a24f4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*TCPListener).accept(0x1efe0c0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x1c45ef0 sp=0x1c45ed8 pc=0x2ba5f4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net.(*TCPListener).Accept(0x1efe0c0) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x1c45f0c sp=0x1c45ef0 pc=0x2b9660 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*onceCloseListener).Accept(0x1f6ae80) Aug 27 18:53:13 volumio-vick go-librespot[5019]: :1 +0x34 fp=0x1c45f24 sp=0x1c45f0c pc=0x45e904 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.(*Server).Serve(0x1d1f048, {0x724fbc, 0x1efe0c0}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x1c45fbc sp=0x1c45f24 pc=0x43cfc0 Aug 27 18:53:13 volumio-vick go-librespot[5019]: net/http.Serve(...) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Aug 27 18:53:13 volumio-vick go-librespot[5019]: go-librespot/zeroconf.(*Zeroconf).Serve.func2() Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x8c fp=0x1c45fec sp=0x1c45fbc pc=0x528bd4 Aug 27 18:53:13 volumio-vick go-librespot[5019]: runtime.goexit({}) Aug 27 18:53:13 volumio-vick go-librespot[5019]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c45fec sp=0x1c45fec pc=0x9346c Aug 27 18:53:13 volumio-vick go-librespot[5019]: created by go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Aug 27 18:53:13 volumio-vick go-librespot[5019]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x160 Aug 27 18:53:13 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Aug 27 18:53:13 volumio-vick volumio[995]: info: Connection to go-librespot Websocket closed Aug 27 18:53:13 volumio-vick go-librespot[5019]: Aborted Aug 27 18:53:13 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:15 volumio-vick volumio[995]: error: Failed request for metavolumio API Aug 27 18:53:15 volumio-vick wpa_supplicant[908]: wlan0: Associated with 58:96:30:a2:de:01 Aug 27 18:53:15 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-CONNECTED - Connection to 58:96:30:a2:de:01 completed [id=0 id_str=] Aug 27 18:53:15 volumio-vick dhcpcd[724]: wlan0: carrier acquired Aug 27 18:53:15 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 18:53:15 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Aug 27 18:53:15 volumio-vick dhcpcd[724]: wlan0: IAID 32:b3:87:81 Aug 27 18:53:16 volumio-vick dhcpcd[724]: wlan0: rebinding lease of 192.168.0.69 Aug 27 18:53:16 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:16 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:16 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:16 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Aug 27 18:53:16 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:16 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:16 volumio-vick go-librespot[10163]: Librespot-go daemon starting... Aug 27 18:53:16 volumio-vick go-librespot[10163]: time="2024-08-27T18:53:16-07:00" level=info msg="generated new device id: a37e0486aaad2ecab6ae59e2907b94b2bc637ae6" Aug 27 18:53:16 volumio-vick go-librespot[10163]: time="2024-08-27T18:53:16-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:16 volumio-vick go-librespot[10163]: time="2024-08-27T18:53:16-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:16 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:16 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:16 volumio-vick dhcpcd[724]: wlan0: soliciting an IPv6 router Aug 27 18:53:19 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:19 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:19 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:19 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Aug 27 18:53:19 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:19 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:19 volumio-vick go-librespot[10170]: Librespot-go daemon starting... Aug 27 18:53:19 volumio-vick go-librespot[10170]: time="2024-08-27T18:53:19-07:00" level=info msg="generated new device id: 837679cb83c69ca88a60fefe883b1259186833c5" Aug 27 18:53:19 volumio-vick go-librespot[10170]: time="2024-08-27T18:53:19-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:19 volumio-vick go-librespot[10170]: time="2024-08-27T18:53:19-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:19 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:19 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:20 volumio-vick volumio[995]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008 Aug 27 18:53:20 volumio-vick dhcpcd[724]: wlan0: probing address 192.168.0.69/24 Aug 27 18:53:22 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:22 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:22 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:22 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Aug 27 18:53:22 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:22 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:22 volumio-vick go-librespot[10177]: Librespot-go daemon starting... Aug 27 18:53:22 volumio-vick go-librespot[10177]: time="2024-08-27T18:53:22-07:00" level=info msg="generated new device id: 6b3025cde93326df1d6100646d361e2c5bdbc6cd" Aug 27 18:53:22 volumio-vick go-librespot[10177]: time="2024-08-27T18:53:22-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:22 volumio-vick go-librespot[10177]: time="2024-08-27T18:53:22-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:22 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:22 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:23 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-DISCONNECTED bssid=58:96:30:a2:de:01 reason=3 Aug 27 18:53:23 volumio-vick dhcpcd[724]: wlan0: carrier lost Aug 27 18:53:23 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Aug 27 18:53:23 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Aug 27 18:53:25 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:25 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:26 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:26 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Aug 27 18:53:26 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:26 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:26 volumio-vick go-librespot[10205]: Librespot-go daemon starting... Aug 27 18:53:26 volumio-vick go-librespot[10205]: time="2024-08-27T18:53:26-07:00" level=info msg="generated new device id: 48d6726f5a72bf446d8b76e1415b4fc9504b452c" Aug 27 18:53:26 volumio-vick go-librespot[10205]: time="2024-08-27T18:53:26-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:26 volumio-vick go-librespot[10205]: time="2024-08-27T18:53:26-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:26 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:26 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:26 volumio-vick wpa_supplicant[908]: wlan0: Trying to associate with SSID 'vickHome-5G' Aug 27 18:53:28 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:28 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:29 volumio-vick nmbd[753]: [2024/08/27 18:53:29.158846, 0] ../source3/libsmb/nmblib.c:917(send_udp) Aug 27 18:53:29 volumio-vick nmbd[753]: Packet send failed to 192.168.0.255(138) ERRNO=Network is unreachable Aug 27 18:53:29 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:29 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Aug 27 18:53:29 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:29 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:29 volumio-vick go-librespot[10213]: Librespot-go daemon starting... Aug 27 18:53:29 volumio-vick go-librespot[10213]: time="2024-08-27T18:53:29-07:00" level=info msg="generated new device id: 7eb326e622acfc9628992bfc79c2b5772f2d3645" Aug 27 18:53:29 volumio-vick go-librespot[10213]: time="2024-08-27T18:53:29-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:29 volumio-vick go-librespot[10213]: time="2024-08-27T18:53:29-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:29 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:29 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:29 volumio-vick ntpd[793]: Soliciting pool server 155.248.196.28 Aug 27 18:53:29 volumio-vick wpa_supplicant[908]: wlan0: Associated with 58:96:30:a2:de:01 Aug 27 18:53:29 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-CONNECTED - Connection to 58:96:30:a2:de:01 completed [id=0 id_str=] Aug 27 18:53:29 volumio-vick dhcpcd[724]: wlan0: carrier acquired Aug 27 18:53:29 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 18:53:29 volumio-vick wpa_supplicant[908]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Aug 27 18:53:29 volumio-vick dhcpcd[724]: wlan0: IAID 32:b3:87:81 Aug 27 18:53:29 volumio-vick dhcpcd[724]: wlan0: soliciting an IPv6 router Aug 27 18:53:30 volumio-vick dhcpcd[724]: wlan0: rebinding lease of 192.168.0.69 Aug 27 18:53:30 volumio-vick dhcpcd[724]: wlan0: probing address 192.168.0.69/24 Aug 27 18:53:31 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:31 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:32 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:32 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Aug 27 18:53:32 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:32 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:32 volumio-vick go-librespot[10221]: Librespot-go daemon starting... Aug 27 18:53:32 volumio-vick go-librespot[10221]: time="2024-08-27T18:53:32-07:00" level=info msg="generated new device id: cf86077d312b33bdd59ac0fe0d19b0317a7d16c8" Aug 27 18:53:32 volumio-vick go-librespot[10221]: time="2024-08-27T18:53:32-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:32 volumio-vick go-librespot[10221]: time="2024-08-27T18:53:32-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:32 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:32 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:34 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:34 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:35 volumio-vick dhcpcd[724]: wlan0: leased 192.168.0.69 for 172800 seconds Aug 27 18:53:35 volumio-vick avahi-daemon[649]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.69. Aug 27 18:53:35 volumio-vick dhcpcd[724]: wlan0: adding route to 192.168.0.0/24 Aug 27 18:53:35 volumio-vick dhcpcd[724]: wlan0: adding default route via 192.168.0.1 Aug 27 18:53:35 volumio-vick avahi-daemon[649]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 18:53:35 volumio-vick avahi-daemon[649]: Registering new address record for 192.168.0.69 on wlan0.IPv4. Aug 27 18:53:35 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:35 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Aug 27 18:53:35 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:35 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:35 volumio-vick go-librespot[10251]: Librespot-go daemon starting... Aug 27 18:53:35 volumio-vick go-librespot[10251]: time="2024-08-27T18:53:35-07:00" level=info msg="generated new device id: 1ed0c081e6f3847817785a59e3e11db61edeaf1c" Aug 27 18:53:35 volumio-vick go-librespot[10251]: time="2024-08-27T18:53:35-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:36 volumio-vick ntpd[793]: Listen normally on 7 wlan0 192.168.0.69:123 Aug 27 18:53:36 volumio-vick ntpd[793]: new interface(s) found: waking up resolver Aug 27 18:53:37 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:39 volumio-vick volumio[995]: verbose: New Socket.io Connection to 192.168.0.69 from 192.168.0.123 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 18:53:39 volumio-vick volumio[995]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 27 18:53:39 volumio-vick volumio[995]: info: Received Get System Info Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:53:39 volumio-vick volumio[995]: info: Discovery: Getting this device information Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:53:39 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:53:39 volumio-vick volumio[995]: info: Listing playlists Aug 27 18:53:42 volumio-vick volumio[995]: info: Executing endpoint metavolumio Aug 27 18:53:42 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 27 18:53:49 volumio-vick volumio[995]: error: Failed request for metavolumio API Aug 27 18:53:53 volumio-vick go-librespot[10251]: time="2024-08-27T18:53:53-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 18:53:53 volumio-vick systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 18:53:53 volumio-vick systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 18:53:54 volumio-vick volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 18:53:57 volumio-vick systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 18:53:57 volumio-vick systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Aug 27 18:53:57 volumio-vick systemd[1]: Stopped go-librespot Daemon. Aug 27 18:53:57 volumio-vick systemd[1]: Started go-librespot Daemon. Aug 27 18:53:57 volumio-vick go-librespot[10260]: Librespot-go daemon starting... Aug 27 18:53:57 volumio-vick go-librespot[10260]: time="2024-08-27T18:53:57-07:00" level=info msg="generated new device id: b9cb58cf4e1144b9c39d40ae733db1e6f6abc747" Aug 27 18:53:57 volumio-vick go-librespot[10260]: time="2024-08-27T18:53:57-07:00" level=debug msg="stored credentials found for 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:53:57 volumio-vick volumio[995]: info: Initializing connection to go-librespot Websocket Aug 27 18:53:59 volumio-vick ntpd[793]: Soliciting pool server 5.161.184.148 Aug 27 18:54:06 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:06-07:00" level=debug msg="new websocket client" Aug 27 18:54:06 volumio-vick volumio[995]: info: Connection to go-librespot Websocket established Aug 27 18:54:09 volumio-vick volumio[995]: info: Getting Spotify volume Aug 27 18:54:09 volumio-vick volumio[995]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 27 18:54:09 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:54:09 volumio-vick volumio[995]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 27 18:54:12 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:12-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 27 18:54:12 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:12-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 27 18:54:12 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:12-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 27 18:54:12 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:12-07:00" level=debug msg="zeroconf server listening on port 33403" Aug 27 18:54:12 volumio-vick volumio[995]: info: Discovery: adding ec082052-f70f-4f91-95e7-a6248a6b6b18 Aug 27 18:54:12 volumio-vick volumio[995]: info: Discovery: Found device Volumio-vick Aug 27 18:54:12 volumio-vick volumio[995]: info: CoreCommandRouter::volumioGetState Aug 27 18:54:15 volumio-vick ntpd[793]: Soliciting pool server 135.148.100.14 Aug 27 18:54:17 volumio-vick ntpd[793]: Soliciting pool server 2603:c020:0:8369:fec0:b7f:603:2601 Aug 27 18:54:21 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:21-07:00" level=debug msg="obtained new client token: AAA9Ah9GQIhCdQGNkBgNS1uCHy1TX/Jhb04p52IUSefYjl668kJxRhFdpp1WBfznAJDt2DG2G9jfXsnMR0u3Hq4V+ASu4ZvXGcBDjOLFwjqTAbAsB7DWTOmdE6Q6GoxvMLZohVKf+l5tYe/rEeZVtRy12SgxqmJBAw/va9jy5Xa+KR0KVvo/aYkDiflRyvAazSmROTgB1A2V+tcOGPao6Jz4Hk039vakj1azyEhMFgEsQkFCKsUbbRC42bMf" Aug 27 18:54:22 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:22-07:00" level=debug msg="completed keyexchange" Aug 27 18:54:22 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:22-07:00" level=debug msg="completed challenge" Aug 27 18:54:22 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:22-07:00" level=debug msg="authenticated as 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:54:23 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:23-07:00" level=debug msg="authenticated as 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="dealer connection opened" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="initializing zeroconf session, username: 31a72ph6evgmjx3wwf5lzauazstu" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="autoplay enabled: false" Aug 27 18:54:27 volumio-vick volumio[995]: info: Spotify volume: 100 Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="received connection id: Y2RiMjFiYWItYzFkYS00MWE0LTgyNzgtMGNmMTM0ZmU1MGUxK2RlYWxlcit0Y3A6Ly8wYWNiZDg1YS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArMzMxNzgwNzQ5N0JBNDM1MDA4MUQ2NDAwQjNBQUUwMjU1NjRBN0FGRDBCQjJGRTIxQjExNTIyMjAxQzQ0QTI3Qg==" Aug 27 18:54:27 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:54:27 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:54:27 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:54:27 volumio-vick volumio[995]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:54:27 volumio-vick go-librespot[10260]: time="2024-08-27T18:54:27-07:00" level=debug msg="put connect state because NEW_DEVICE" Aug 27 18:54:31 volumio-vick volumio[995]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 18:54:31 volumio-vick volumio[995]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Aug 27 18:54:31 volumio-vick volumio[995]: code: 'auth/network-request-failed', Aug 27 18:54:31 volumio-vick volumio[995]: a: null Aug 27 18:54:31 volumio-vick volumio[995]: } Aug 27 18:54:31 volumio-vick volumio[995]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 18:54:31 volumio-vick sudo[10319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 18:53 Aug 27 18:54:31 volumio-vick sudo[10319]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"