Sep 01 02:15:00 volumio volumio5-onboarding[1482]: time=2026-09-01T02:15:00.381+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 02:15:06 volumio wpa_supplicant[1160]: wlan0: Failed to initiate sched scan Sep 01 02:15:07 volumio volumio[1201]: info: Received Get System Info Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 02:15:07 volumio volumio[1201]: info: Discovery: Getting this device information Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::volumioGetState Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 02:15:07 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 02:15:08 volumio volumio5-onboarding[1482]: time=2026-09-01T02:15:08.218+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 02:15:14 volumio wpa_supplicant[1160]: wlan0: Failed to initiate sched scan Sep 01 02:15:15 volumio volumio[1201]: info: Received Get System Info Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 02:15:15 volumio volumio[1201]: info: Discovery: Getting this device information Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::volumioGetState Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 02:15:15 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 02:15:16 volumio volumio5-onboarding[1482]: time=2026-09-01T02:15:16.034+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Sep 01 02:15:20 volumio go-librespot[1595]: time="2026-09-01T02:15:20+09: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" Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: Trying to associate with 36:c5:99:e1:25:cc (SSID='elpis' freq=2412 MHz) Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: Associated with 36:c5:99:e1:25:cc Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=KR Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: WPA: Key negotiation completed with 36:c5:99:e1:25:cc [PTK=CCMP GTK=CCMP] Sep 01 02:15:22 volumio wpa_supplicant[1160]: wlan0: CTRL-EVENT-CONNECTED - Connection to 36:c5:99:e1:25:cc completed [id=0 id_str=] Sep 01 02:15:22 volumio dhcpcd[762]: wlan0: carrier acquired Sep 01 02:15:22 volumio dhcpcd[762]: wlan0: IAID eb:a4:b2:84 Sep 01 02:15:22 volumio dhcpcd[762]: wlan0: soliciting an IPv6 router Sep 01 02:15:22 volumio dhcpcd[762]: wlan0: rebinding lease of 192.168.1.160 Sep 01 02:15:23 volumio dhcpcd[762]: wlan0: probing address 192.168.1.160/24 Sep 01 02:15:23 volumio volumio[1201]: info: Received Get System Info Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 02:15:23 volumio volumio[1201]: info: Discovery: Getting this device information Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::volumioGetState Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 02:15:23 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 02:15:23 volumio volumio5-onboarding[1482]: time=2026-09-01T02:15:23.951+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 02:15:27 volumio dhcpcd[762]: wlan0: leased 192.168.1.160 for 86400 seconds Sep 01 02:15:27 volumio avahi-daemon[1308]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.160. Sep 01 02:15:27 volumio dhcpcd[762]: wlan0: adding route to 192.168.1.0/24 Sep 01 02:15:27 volumio dhcpcd[762]: wlan0: adding default route via 192.168.1.1 Sep 01 02:15:27 volumio avahi-daemon[1308]: New relevant interface wlan0.IPv4 for mDNS. Sep 01 02:15:27 volumio avahi-daemon[1308]: Registering new address record for 192.168.1.160 on wlan0.IPv4. Sep 01 02:15:27 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Sep 01 02:15:27 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Sep 01 02:15:27 volumio systemd[1]: welcome.service: Deactivated successfully. Sep 01 02:15:27 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Sep 01 02:15:27 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Sep 01 02:15:28 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Sep 01 02:15:28 volumio welcome[12219]: Resolved ip:[1] 192.168.1.160 Sep 01 02:15:28 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Sep 01 02:15:28 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Sep 01 02:15:28 volumio volumio[1201]: info: Received Get System Info Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 02:15:28 volumio volumio[1201]: info: Discovery: Getting this device information Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::volumioGetState Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 02:15:28 volumio volumio[1201]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 02:15:29 volumio volumio[1201]: info: Discovery: adding 4f630fd3-7dbd-4b48-87ad-818e10500344 Sep 01 02:15:29 volumio volumio[1201]: info: Discovery: Found device volumio Sep 01 02:15:29 volumio volumio[1201]: info: CoreCommandRouter::volumioGetState Sep 01 02:15:29 volumio ntpd[914]: IO: Listen normally on 5 wlan0 192.168.1.160:123 Sep 01 02:15:29 volumio ntpd[914]: IO: new interface(s) found: waking up resolver Sep 01 02:15:29 volumio volumio5-onboarding[1482]: time=2026-09-01T02:15:29.259+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 02:15:29 volumio volumio[1201]: info: Volumio Network Manager: Network status updated: 2 Sep 01 02:15:44 volumio go-librespot[1595]: time="2026-09-01T02:15:44+09:00" level=error msg="did not receive last pong ack from accesspoint, 255s passed" Sep 01 02:15:44 volumio go-librespot[1595]: panic: runtime error: invalid memory address or nil pointer dereference Sep 01 02:15:44 volumio go-librespot[1595]: [signal SIGSEGV: segmentation violation code=0x1 addr=0xc pc=0x4f7ef0] Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 106 gp=0x29d05a8 m=8 mp=0x2889808 [running]: Sep 01 02:15:44 volumio go-librespot[1595]: panic({0x841d88, 0xfa0250}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/panic.go:802 +0x148 fp=0x2859f20 sp=0x2859ecc pc=0xa92ec Sep 01 02:15:44 volumio go-librespot[1595]: runtime.panicmem(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/panic.go:262 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.sigpanic() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/signal_unix.go:925 +0x384 fp=0x2859f50 sp=0x2859f20 pc=0xabca4 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0x2a5c6e8) Sep 01 02:15:44 volumio go-librespot[1595]: /src/ap/ap.go:380 +0x284 fp=0x2859fe4 sp=0x2859f54 pc=0x4f7ef0 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap2() Sep 01 02:15:44 volumio go-librespot[1595]: /src/ap/ap.go:277 +0x28 fp=0x2859fec sp=0x2859fe4 pc=0x4f73c4 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2859fec sp=0x2859fec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 98 Sep 01 02:15:44 volumio go-librespot[1595]: /src/ap/ap.go:277 +0x15c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 1 gp=0x2802128 m=nil [select, 74178 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2c31ce0 sp=0x2c31ccc pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.selectgo(0x2c31df0, 0x29dbdbc, 0x0, 0x0, 0x2, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2c31d90 sp=0x2c31ce0 pc=0x85000 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x289de60, 0x2c31e90) Sep 01 02:15:44 volumio go-librespot[1595]: /src/zeroconf/zeroconf.go:300 +0x228 fp=0x2c31e38 sp=0x2c31d90 pc=0x62f43c Sep 01 02:15:44 volumio go-librespot[1595]: main.(*App).withAppPlayer(0x299c380, {0xa3da1c, 0x1005090}, 0x2811450) Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/main.go:340 +0x5dc fp=0x2c31ed0 sp=0x2c31e38 pc=0x6bcc60 Sep 01 02:15:44 volumio go-librespot[1595]: main.(*App).withCredentials(...) Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/main.go:209 Sep 01 02:15:44 volumio go-librespot[1595]: main.(*App).SpotifyToken(0x299c380, {0xa3da1c, 0x1005090}, {0x2990660, 0x19}, {0x29a2140, 0x13a}) Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/main.go:201 +0xc0 fp=0x2c31f00 sp=0x2c31ed0 pc=0x6bc02c Sep 01 02:15:44 volumio go-librespot[1595]: main.main() Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/main.go:620 +0x660 fp=0x2c31fa8 sp=0x2c31f00 pc=0x6bf56c Sep 01 02:15:44 volumio go-librespot[1595]: runtime.main() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:285 +0x2f0 fp=0x2c31fec sp=0x2c31fa8 pc=0x6f390 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2c31fec sp=0x2c31fec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 2 gp=0x28027e8 m=nil [force gc (idle), 2 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97746c, 0xff8fa8, 0x11, 0xa, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2848fd4 sp=0x2848fc0 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goparkunlock(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:466 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.forcegchelper() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:373 +0xe4 fp=0x2848fec sp=0x2848fd4 pc=0x6f7f4 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2848fec sp=0x2848fec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.init.6 in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:361 +0x1c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 3 gp=0x2802b48 m=nil [GC sweep wait]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97746c, 0xff9850, 0xc, 0x9, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x28497c4 sp=0x28497b0 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goparkunlock(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:466 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.bgsweep(0x282e050) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgcsweep.go:323 +0x11c fp=0x28497e4 sp=0x28497c4 pc=0x5768c Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcenable.gowrap1() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:212 +0x28 fp=0x28497ec sp=0x28497e4 pc=0x46c3c Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x28497ec sp=0x28497ec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.gcenable in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:212 +0x74 Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 4 gp=0x2802c68 m=nil [GC scavenge wait]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97746c, 0xffa170, 0xd, 0xa, 0x2) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2849fb4 sp=0x2849fa0 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goparkunlock(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:466 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.(*scavengerState).park(0xffa170) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x2849fc8 sp=0x2849fb4 pc=0x54a28 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.bgscavenge(0x282e050) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x2849fe4 sp=0x2849fc8 pc=0x5516c Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcenable.gowrap2() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:213 +0x28 fp=0x2849fec sp=0x2849fe4 pc=0x46be8 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2849fec sp=0x2849fec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.gcenable in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:213 +0xbc Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 5 gp=0x2802fc8 m=nil [GOMAXPROCS updater (idle), 74178 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97746c, 0xff95e8, 0x12, 0xa, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x284a7a4 sp=0x284a790 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goparkunlock(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:466 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.updateMaxProcsGoroutine() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:6720 +0x110 fp=0x284a7ec sp=0x284a7a4 pc=0x7f174 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x284a7ec sp=0x284a7ec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.defaultGOMAXPROCSUpdateEnable in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:6708 +0x40 Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 6 gp=0x2803328 m=nil [finalizer wait, 74177 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x977314, 0x1005180, 0x10, 0xa, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x284af88 sp=0x284af74 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.runFinalizers() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mfinal.go:210 +0x110 fp=0x284afec sp=0x284af88 pc=0x45888 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x284afec sp=0x284afec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.createfing in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mfinal.go:172 +0x5c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 7 gp=0x2803448 m=nil [cleanup wait, 4889 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97746c, 0xffa348, 0x2e, 0xa, 0x1) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x284b7a4 sp=0x284b790 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goparkunlock(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:466 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.(*cleanupQueue).dequeue(0xffa2e8) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mcleanup.go:439 +0x12c fp=0x284b7c4 sp=0x284b7a4 pc=0x41cb0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.runCleanups() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mcleanup.go:635 +0x7c fp=0x284b7ec sp=0x284b7c4 pc=0x4284c Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x284b7ec sp=0x284b7ec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.(*cleanupQueue).createGs in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mcleanup.go:589 +0x124 Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 10 gp=0x29d06c8 m=nil [IO wait, 74178 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97745c, 0x7609fe10, 0x2, 0x2, 0x5) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x28444f0 sp=0x28444dc pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.netpollblock(0x7609fe00, 0x72, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2844508 sp=0x28444f0 pc=0x675a0 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.runtime_pollWait(0x7609fe00, 0x72) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x284451c sp=0x2844508 pc=0xa8864 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*pollDesc).wait(0x29b11e8, 0x72, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2844530 sp=0x284451c pc=0x136044 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*pollDesc).waitRead(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*FD).Accept(0x29b11d0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x2844578 sp=0x2844530 pc=0x13a800 Sep 01 02:15:44 volumio go-librespot[1595]: net.(*netFD).accept(0x29b11d0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x28445e0 sp=0x2844578 pc=0x1abc28 Sep 01 02:15:44 volumio go-librespot[1595]: net.(*TCPListener).accept(0x2800480) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x2844634 sp=0x28445e0 pc=0x1c3554 Sep 01 02:15:44 volumio go-librespot[1595]: net.(*TCPListener).Accept(0x2800480) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x2844650 sp=0x2844634 pc=0x1c259c Sep 01 02:15:44 volumio go-librespot[1595]: net/http.(*onceCloseListener).Accept(0x28a6580) Sep 01 02:15:44 volumio go-librespot[1595]: :1 +0x34 fp=0x2844668 sp=0x2844650 pc=0x367f9c Sep 01 02:15:44 volumio go-librespot[1595]: net/http.(*Server).Serve(0x28de0b8, {0xa3d218, 0x2800480}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x2844700 sp=0x2844668 pc=0x341154 Sep 01 02:15:44 volumio go-librespot[1595]: net/http.Serve(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2971 Sep 01 02:15:44 volumio go-librespot[1595]: main.(*ConcreteApiServer).serve(0x282a3c0) Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/api_server.go:666 +0x974 fp=0x28447e4 sp=0x2844700 pc=0x6b17bc Sep 01 02:15:44 volumio go-librespot[1595]: main.NewApiServer.gowrap1() Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/api_server.go:332 +0x28 fp=0x28447ec sp=0x28447e4 pc=0x6b04f4 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x28447ec sp=0x28447ec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by main.NewApiServer in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /src/cmd/daemon/api_server.go:332 +0x310 Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 37 gp=0x2b30008 m=nil [IO wait, 74178 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x97745c, 0x7609f810, 0x2, 0x2, 0x5) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b3fcbc sp=0x2b3fca8 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.netpollblock(0x7609f800, 0x72, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2b3fcd4 sp=0x2b3fcbc pc=0x675a0 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.runtime_pollWait(0x7609f800, 0x72) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2b3fce8 sp=0x2b3fcd4 pc=0xa8864 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*pollDesc).wait(0x29028d8, 0x72, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2b3fcfc sp=0x2b3fce8 pc=0x136044 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*pollDesc).waitRead(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 02:15:44 volumio go-librespot[1595]: internal/poll.(*FD).ReadMsg(0x29028c0, {0x2a42000, 0x10, 0x10}, {0x28d6618, 0x1000, 0x1000}, 0x40000000) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_unix.go:295 +0x2c0 fp=0x2b3fd6c sp=0x2b3fcfc pc=0x1381bc Sep 01 02:15:44 volumio go-librespot[1595]: net.(*netFD).readMsg(0x29028c0, {0x2a42000, 0x10, 0x10}, {0x28d6618, 0x1000, 0x1000}, 0x40000000) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/fd_posix.go:91 +0x58 fp=0x2b3fdc8 sp=0x2b3fd6c pc=0x1aa2c8 Sep 01 02:15:44 volumio go-librespot[1595]: net.(*UnixConn).readMsg(0x289bcc8, {0x2a42000, 0x10, 0x10}, {0x28d6618, 0x1000, 0x1000}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/unixsock_posix.go:115 +0x58 fp=0x2b3fe28 sp=0x2b3fdc8 pc=0x1c9d80 Sep 01 02:15:44 volumio go-librespot[1595]: net.(*UnixConn).ReadMsgUnix(0x289bcc8, {0x2a42000, 0x10, 0x10}, {0x28d6618, 0x1000, 0x1000}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/net/unixsock.go:143 +0x58 fp=0x2b3fe78 sp=0x2b3fe28 pc=0x1c820c Sep 01 02:15:44 volumio go-librespot[1595]: github.com/godbus/dbus/v5.(*oobReader).Read(0x28d6608, {0x2a42000, 0x10, 0x10}) Sep 01 02:15:44 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:41 +0x50 fp=0x2b3fec8 sp=0x2b3fe78 pc=0x4c2af0 Sep 01 02:15:44 volumio go-librespot[1595]: io.ReadAtLeast({0xa39d58, 0x28d6608}, {0x2a42000, 0x10, 0x10}, 0x10) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/io/io.go:335 +0x90 fp=0x2b3fef4 sp=0x2b3fec8 pc=0xee954 Sep 01 02:15:44 volumio go-librespot[1595]: io.ReadFull(...) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/io/io.go:354 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/godbus/dbus/v5.(*unixTransport).ReadMessage(0x2810e60) Sep 01 02:15:44 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:124 +0x224 fp=0x2b3ffa0 sp=0x2b3fef4 pc=0x4c32c4 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/godbus/dbus/v5.(*Conn).inWorker(0x299c200) Sep 01 02:15:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Sep 01 02:15:44 volumio volumio[1201]: info: Connection to go-librespot Websocket closed Sep 01 02:15:44 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:390 +0x44 fp=0x2b3ffe4 sp=0x2b3ffa0 pc=0x4aaef4 Sep 01 02:15:44 volumio go-librespot[1595]: github.com/godbus/dbus/v5.(*Conn).Auth.gowrap1() Sep 01 02:15:44 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x28 fp=0x2b3ffec sp=0x2b3ffe4 pc=0x4a8318 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b3ffec sp=0x2b3ffec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by github.com/godbus/dbus/v5.(*Conn).Auth in goroutine 1 Sep 01 02:15:44 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x77c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 20 gp=0x2b30248 m=nil [GC worker (idle), 2 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x977320, 0x2ba2400, 0x1c, 0xa, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b42f88 sp=0x2b42f74 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcBgMarkWorker(0x2b29900) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2b42fe4 sp=0x2b42f88 pc=0x49f34 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2b42fec sp=0x2b42fe4 pc=0x49e14 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b42fec sp=0x2b42fec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.gcBgMarkStartWorkers in goroutine 14 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 21 gp=0x2b30368 m=nil [GC worker (idle), 51843 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x977320, 0x2ba2600, 0x1c, 0xa, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2d26788 sp=0x2d26774 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcBgMarkWorker(0x2b29900) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2d267e4 sp=0x2d26788 pc=0x49f34 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2d267ec sp=0x2d267e4 pc=0x49e14 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2d267ec sp=0x2d267ec pc=0xb0874 Sep 01 02:15:44 volumio go-librespot[1595]: created by runtime.gcBgMarkStartWorkers in goroutine 14 Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 02:15:44 volumio go-librespot[1595]: goroutine 22 gp=0x2b30488 m=nil [GC worker (idle), 54414 minutes]: Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gopark(0x977320, 0x2ba2800, 0x1c, 0xa, 0x0) Sep 01 02:15:44 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b37788 sp=0x2b37774 pc=0xa97c0 Sep 01 02:15:44 volumio go-librespot[1595]: runtime.gcBgMarkWorker(0x2b29900) Sep 01 02:15:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2b377e4 sp=0x2b37788 pc=0x49f34 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2b377ec sp=0x2b377e4 pc=0x49e14 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b377ec sp=0x2b377ec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by runtime.gcBgMarkStartWorkers in goroutine 14 Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 23 gp=0x2b305a8 m=nil [GC worker (idle), 4859 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x977320, 0x2ba2a00, 0x1c, 0xa, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2d2cf88 sp=0x2d2cf74 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gcBgMarkWorker(0x2b29900) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2d2cfe4 sp=0x2d2cf88 pc=0x49f34 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2d2cfec sp=0x2d2cfe4 pc=0x49e14 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2d2cfec sp=0x2d2cfec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by runtime.gcBgMarkStartWorkers in goroutine 14 Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 24 gp=0x288afc8 m=nil [chan receive, 74178 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x9772f4, 0x2b29638, 0xe, 0x7, 0x2) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b36778 sp=0x2b36764 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv(0x2b29600, 0x0, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2b367c0 sp=0x2b36778 pc=0x3414c Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv1(0x2b29600, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:509 +0x20 fp=0x2b367d4 sp=0x2b367c0 pc=0x33bcc Sep 01 02:15:45 volumio go-librespot[1595]: github.com/godbus/dbus/v5.newConn.func1() Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:303 +0x40 fp=0x2b367ec sp=0x2b367d4 pc=0x4aa8ec Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b367ec sp=0x2b367ec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by github.com/godbus/dbus/v5.newConn in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:302 +0x52c Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 49 gp=0x288b328 m=nil [select, 74178 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 02:15:44 volumio systemd[1]: go-librespot-daemon.service: Consumed 1month 5d 14h 20min 46.544s CPU time. Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b35674 sp=0x2b35660 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.selectgo(0x2b35780, 0x2b3574c, 0x0, 0x0, 0x3, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2b35724 sp=0x2b35674 pc=0x85000 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0x29b1590) Sep 01 02:15:45 volumio go-librespot[1595]: /src/player/player.go:215 +0x1f4 fp=0x2b357e4 sp=0x2b35724 pc=0x582954 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Sep 01 02:15:45 volumio go-librespot[1595]: /src/player/player.go:197 +0x28 fp=0x2b357ec sp=0x2b357e4 pc=0x58253c Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b357ec sp=0x2b357ec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/player/player.go:197 +0x220 Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 32 gp=0x288b568 m=nil [IO wait, 74178 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x97745c, 0x7609f210, 0x2, 0x2, 0x5) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2c23908 sp=0x2c238f4 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.netpollblock(0x7609f200, 0x72, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2c23920 sp=0x2c23908 pc=0x675a0 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.runtime_pollWait(0x7609f200, 0x72) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2c23934 sp=0x2c23920 pc=0xa8864 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*pollDesc).wait(0x2c16388, 0x72, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2c23948 sp=0x2c23934 pc=0x136044 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*pollDesc).waitRead(...) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*FD).Read(0x2c16370, {0x29eb000, 0x1000, 0x1000}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_unix.go:165 +0x22c fp=0x2c23990 sp=0x2c23948 pc=0x1371c4 Sep 01 02:15:45 volumio go-librespot[1595]: net.(*netFD).Read(0x2c16370, {0x29eb000, 0x1000, 0x1000}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/fd_posix.go:68 +0x38 fp=0x2c239bc sp=0x2c23990 pc=0x1a9e78 Sep 01 02:15:45 volumio go-librespot[1595]: net.(*conn).Read(0x29ee4e8, {0x29eb000, 0x1000, 0x1000}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/net.go:196 +0x48 fp=0x2c239e8 sp=0x2c239bc pc=0x1b967c Sep 01 02:15:45 volumio go-librespot[1595]: io.(*multiReader).Read(0x2811eb0, {0x29eb000, 0x1000, 0x1000}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x2c23a14 sp=0x2c239e8 pc=0xefb88 Sep 01 02:15:45 volumio go-librespot[1595]: bufio.(*Reader).fill(0x29cfd70) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/bufio/bufio.go:113 +0x10c fp=0x2c23a38 sp=0x2c23a14 pc=0x2b6c1c Sep 01 02:15:45 volumio go-librespot[1595]: bufio.(*Reader).ReadByte(0x29cfd70) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/bufio/bufio.go:273 +0x28 fp=0x2c23a44 sp=0x2c23a38 pc=0x2b7498 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.readFrameHeader(0x29cfd70, {0x293cab8, 0x8, 0x8}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/frame.go:55 +0x68 fp=0x2c23a84 sp=0x2c23a44 pc=0x372a08 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.(*Conn).readFrameHeader(0x293ca88, {0xa3da00, 0x1005090}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:266 +0xd0 fp=0x2c23b08 sp=0x2c23a84 pc=0x375bd4 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.(*Conn).readLoop(0x293ca88, {0xa3da00, 0x1005090}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:185 +0x3c fp=0x2c23bcc sp=0x2c23b08 pc=0x375390 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.(*Conn).reader(0x293ca88, {0xa3da00, 0x1005090}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:381 +0xec fp=0x2c23c50 sp=0x2c23bcc pc=0x376798 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.(*Conn).Reader(...) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:36 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/coder/websocket.(*Conn).Read(0x293ca88, {0xa3da00, 0x1005090}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:42 +0x30 fp=0x2c23c78 sp=0x2c23c50 pc=0x374944 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*ConcreteApiServer).serve.func17({0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/api_server.go:636 +0x3b4 fp=0x2c23cfc sp=0x2c23c78 pc=0x6b2040 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.HandlerFunc.ServeHTTP(0x289a298, {0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x2c23d0c sp=0x2c23cfc pc=0x33d7d8 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.(*ServeMux).ServeHTTP(0x28aa180, {0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2861 +0x228 fp=0x2c23d4c sp=0x2c23d0c pc=0x33f6c8 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x124 fp=0x2c23d74 sp=0x2c23d4c pc=0x6b19b8 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.HandlerFunc.ServeHTTP(0x28b6230, {0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x2c23d84 sp=0x2c23d74 pc=0x33d7d8 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.serverHandler.ServeHTTP({0x28de0b8}, {0xa3d2d8, 0x2c18218}, 0x2c180b8) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:3340 +0xe0 fp=0x2c23da0 sp=0x2c23d84 pc=0x35cb44 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.(*conn).serve(0x282bda0, {0xa3da38, 0x28b0348}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2109 +0x794 fp=0x2c23fdc sp=0x2c23da0 pc=0x33b894 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.(*Server).Serve.gowrap3() Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:3493 +0x38 fp=0x2c23fec sp=0x2c23fdc pc=0x3415cc Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2c23fec sp=0x2c23fec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by net/http.(*Server).Serve in goroutine 10 Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:3493 +0x42c Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 98 gp=0x288b208 m=nil [runnable]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.selectgo(0x2c21f70, 0x2c21b20, 0x0, 0x0, 0xa, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/select.go:122 +0x14ac fp=0x2c219e0 sp=0x2c219e0 pc=0x85860 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*AppPlayer).Run(0x2902af0, {0xa3da1c, 0x1005090}, 0x2b0bb40, 0x2b0bb80) Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/player.go:661 +0x368 fp=0x2c21fd4 sp=0x2c219e0 pc=0x6c5950 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*App).withAppPlayer.gowrap1() Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:274 +0x48 fp=0x2c21fec sp=0x2c21fd4 pc=0x6bd9f0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2c21fec sp=0x2c21fec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:274 +0x46c Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 99 gp=0x288b7a8 m=nil [chan receive, 74178 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x9772f4, 0x287a1b8, 0xe, 0x7, 0x2) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x284873c sp=0x2848728 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv(0x287a180, 0x28487d0, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2848784 sp=0x284873c pc=0x3414c Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv2(0x287a180, 0x28487d0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x2848798 sp=0x2848784 pc=0x33bf0 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*App).withAppPlayer.func1() Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:284 +0x68 fp=0x28487ec sp=0x2848798 pc=0x6bd918 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x28487ec sp=0x28487ec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:281 +0x4f8 Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 100 gp=0x288bb08 m=nil [chan receive, 74178 minutes]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x9772f4, 0x287a178, 0xe, 0x7, 0x2) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b37f40 sp=0x2b37f2c pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv(0x287a140, 0x2b37fe0, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2b37f88 sp=0x2b37f40 pc=0x3414c Sep 01 02:15:45 volumio go-librespot[1595]: runtime.chanrecv2(0x287a140, 0x2b37fe0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x2b37f9c sp=0x2b37f88 pc=0x33bf0 Sep 01 02:15:45 volumio go-librespot[1595]: main.(*App).withAppPlayer.func2() Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:300 +0x6c fp=0x2b37fec sp=0x2b37f9c pc=0x6bd47c Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b37fec sp=0x2b37fec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/cmd/daemon/main.go:297 +0x598 Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 101 gp=0x288bc28 m=nil [IO wait]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x97745c, 0x7609fa10, 0x2, 0x2, 0x5) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2b38dac sp=0x2b38d98 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.netpollblock(0x7609fa00, 0x72, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2b38dc4 sp=0x2b38dac pc=0x675a0 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.runtime_pollWait(0x7609fa00, 0x72) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2b38dd8 sp=0x2b38dc4 pc=0xa8864 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*pollDesc).wait(0x2902888, 0x72, 0x0) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2b38dec sp=0x2b38dd8 pc=0x136044 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*pollDesc).waitRead(...) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 02:15:45 volumio go-librespot[1595]: internal/poll.(*FD).Accept(0x2902870) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x2b38e34 sp=0x2b38dec pc=0x13a800 Sep 01 02:15:45 volumio go-librespot[1595]: net.(*netFD).accept(0x2902870) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x2b38e9c sp=0x2b38e34 pc=0x1abc28 Sep 01 02:15:45 volumio go-librespot[1595]: net.(*TCPListener).accept(0x29cef00) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x2b38ef0 sp=0x2b38e9c pc=0x1c3554 Sep 01 02:15:45 volumio go-librespot[1595]: net.(*TCPListener).Accept(0x29cef00) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x2b38f0c sp=0x2b38ef0 pc=0x1c259c Sep 01 02:15:45 volumio go-librespot[1595]: net/http.(*onceCloseListener).Accept(0x286f020) Sep 01 02:15:45 volumio go-librespot[1595]: :1 +0x34 fp=0x2b38f24 sp=0x2b38f0c pc=0x367f9c Sep 01 02:15:45 volumio go-librespot[1595]: net/http.(*Server).Serve(0x2c19138, {0xa3d218, 0x29cef00}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x2b38fbc sp=0x2b38f24 pc=0x341154 Sep 01 02:15:45 volumio go-librespot[1595]: net/http.Serve(...) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/net/http/server.go:2971 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Sep 01 02:15:45 volumio go-librespot[1595]: /src/zeroconf/zeroconf.go:297 +0x8c fp=0x2b38fec sp=0x2b38fbc pc=0x62f538 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2b38fec sp=0x2b38fec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Sep 01 02:15:45 volumio go-librespot[1595]: /src/zeroconf/zeroconf.go:297 +0x160 Sep 01 02:15:45 volumio go-librespot[1595]: goroutine 2958 gp=0x29d1328 m=nil [select]: Sep 01 02:15:45 volumio go-librespot[1595]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2c32d78 sp=0x2c32d64 pc=0xa97c0 Sep 01 02:15:45 volumio go-librespot[1595]: runtime.selectgo(0x2c32e7c, 0x2c32e50, 0x0, 0x0, 0x2, 0x1) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2c32e28 sp=0x2c32d78 pc=0x85000 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x2c32ecc, {0xa3c8c0, 0x282a180}, 0x0, {0x0, 0x0}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:112 +0x244 fp=0x2c32ea4 sp=0x2c32e28 pc=0x4eb7bc Sep 01 02:15:45 volumio go-librespot[1595]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x2c32f5c, {0xa3c8c0, 0x282a180}, 0x0, {0x0, 0x0}) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x5c fp=0x2c32ed4 sp=0x2c32ea4 pc=0x4eb180 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/cenkalti/backoff/v4.RetryNotify(...) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/cenkalti/backoff/v4.Retry(...) Sep 01 02:15:45 volumio go-librespot[1595]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0x2a5c6e8) Sep 01 02:15:45 volumio go-librespot[1595]: /src/ap/ap.go:335 +0x434 fp=0x2c32fe4 sp=0x2c32ed4 pc=0x4f7878 Sep 01 02:15:45 volumio go-librespot[1595]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect.gowrap1() Sep 01 02:15:45 volumio go-librespot[1595]: /src/ap/ap.go:403 +0x28 fp=0x2c32fec sp=0x2c32fe4 pc=0x4f81cc Sep 01 02:15:45 volumio go-librespot[1595]: runtime.goexit({}) Sep 01 02:15:45 volumio go-librespot[1595]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2c32fec sp=0x2c32fec pc=0xb0874 Sep 01 02:15:45 volumio go-librespot[1595]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect in goroutine 3013 Sep 01 02:15:45 volumio go-librespot[1595]: /src/ap/ap.go:403 +0x120 Sep 01 02:15:45 volumio go-librespot[1594]: Aborted Sep 01 02:15:47 volumio volumio[1201]: info: Initializing connection to go-librespot Websocket Sep 01 02:15:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 02:15:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:47 volumio systemd[1]: go-librespot-daemon.service: Consumed 1month 5d 14h 20min 46.544s CPU time. Sep 01 02:15:48 volumio volumio[1201]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 02:15:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:48 volumio go-librespot[12256]: go-librespot daemon starting... Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="app state loaded" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=info msg="zeroconf server listening on port 38285" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="obtained new client token: AAGh8G4ZPWhW/bwnAxhLMlqIcaadPwxjh9P7Bjj6/PtsrsGlO8LjN1W4tJZ3fepWdy7S7hozweVvHtPaxtA6C1Y0/mGrhcetHyxrC6H/vX7s/DRkWUt82olLK9DKDM13jLbVvoxaEGcQQhJwVM/tsEr5oA+OXXWG3bjUjexyYWYpciBGnOxoP8U7zzbZXMkPhnV3BJi59It0Tvrc7mhthkghoG6xToAxkrxWiBfzCuJEtIFBiS6DW5vQ" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="completed keyexchange" Sep 01 02:15:48 volumio go-librespot[12257]: time="2026-09-01T02:15:48+09:00" level=debug msg="completed challenge" Sep 01 02:15:49 volumio go-librespot[12257]: time="2026-09-01T02:15:49+09:00" level=info msg="authenticated AP" username="rf*********************zr" Sep 01 02:15:49 volumio go-librespot[12257]: time="2026-09-01T02:15:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 02:15:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:15:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:15:51 volumio volumio[1201]: info: Initializing connection to go-librespot Websocket Sep 01 02:15:51 volumio volumio[1201]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 02:15:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 02:15:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:52 volumio go-librespot[12281]: go-librespot daemon starting... Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="app state loaded" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=info msg="zeroconf server listening on port 34141" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="obtained new client token: AAFNgW5oAIicXDweOnKmGkH9MkSZ09eE33h97X9+lnHMXOC9UqoaEr7esCpkJdbDoDcgFs5gdhMM32UjOwJFyAWM2RH51JQTntfIxduNI+9URjfkyHDQHWdQV+N8RO8+pMHQc53OcqzRDmTUDrKW5PZ5VOwpiTqWIuw4H0Eof108+lhwQZ74uxUnVwsvLItlK6dOw0P3eO5UTLgkzYIL8ADoKOXbInx3o/crEuurnoeg72ta8yZPnaog" Sep 01 02:15:52 volumio go-librespot[12282]: time="2026-09-01T02:15:52+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 02:15:53 volumio go-librespot[12282]: time="2026-09-01T02:15:53+09:00" level=debug msg="completed keyexchange" Sep 01 02:15:53 volumio go-librespot[12282]: time="2026-09-01T02:15:53+09:00" level=debug msg="completed challenge" Sep 01 02:15:53 volumio go-librespot[12282]: time="2026-09-01T02:15:53+09:00" level=info msg="authenticated AP" username="rf*********************zr" Sep 01 02:15:53 volumio go-librespot[12282]: time="2026-09-01T02:15:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 02:15:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:15:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:15:54 volumio volumio[1201]: info: Initializing connection to go-librespot Websocket Sep 01 02:15:54 volumio volumio[1201]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 02:15:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 02:15:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:15:56 volumio go-librespot[12292]: go-librespot daemon starting... Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="app state loaded" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=info msg="zeroconf server listening on port 37849" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="obtained new client token: AAHINEUC5YBcFIEVCee3owC4E87/nm95TbHa2iGjUukG0Ici3wVlJKEvzj45PqQF831Pd8wxIXZ83WAkt/H1bTkd1szlLps+anxIZ3Rstk96y/zj6403+J/b0SoWnnn2fdwi70OoSEh4UVxRkndPgA57xxrFK+ydLTi2w+SjDwR9YeuskQUN3xIdVu5/rW4xYR8M2kBuYEQ3EEZJDIt00hKu69BrGvhuv7veqRxiwCMEIlnrPyZ5T3Vk" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="completed keyexchange" Sep 01 02:15:56 volumio go-librespot[12293]: time="2026-09-01T02:15:56+09:00" level=debug msg="completed challenge" Sep 01 02:15:57 volumio volumio[1201]: info: Initializing connection to go-librespot Websocket Sep 01 02:15:57 volumio volumio[1201]: info: Connection to go-librespot Websocket established Sep 01 02:15:57 volumio go-librespot[12293]: time="2026-09-01T02:15:57+09:00" level=debug msg="new websocket client" Sep 01 02:15:57 volumio go-librespot[12293]: time="2026-09-01T02:15:57+09:00" level=info msg="authenticated AP" username="rf*********************zr" Sep 01 02:15:57 volumio go-librespot[12293]: time="2026-09-01T02:15:57+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 02:15:57 volumio volumio[1201]: info: Connection to go-librespot Websocket closed Sep 01 02:15:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:15:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:16:00 volumio volumio[1201]: info: Getting Spotify volume Sep 01 02:16:00 volumio volumio[1201]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 02:16:00 volumio volumio[1201]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 02:16:00 volumio volumio[1201]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 02:16:00 volumio volumio[1201]: errno: -111, Sep 01 02:16:00 volumio volumio[1201]: code: 'ECONNREFUSED', Sep 01 02:16:00 volumio volumio[1201]: syscall: 'connect', Sep 01 02:16:00 volumio volumio[1201]: address: '127.0.0.1', Sep 01 02:16:00 volumio volumio[1201]: port: 9879, Sep 01 02:16:00 volumio volumio[1201]: response: undefined Sep 01 02:16:00 volumio volumio[1201]: } Sep 01 02:16:00 volumio volumio[1201]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 02:16:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 02:16:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:16:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 02:16:00 volumio go-librespot[12328]: go-librespot daemon starting... Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=info msg="running go-librespot 0.7.1" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="app state loaded" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=info msg="zeroconf server listening on port 46761" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="obtained new client token: AAHiQTXojro/lgmqhV0bzFF0QfwqzQlhX7ZMvb48hzhWBYaOM6g/m0bAVGghHm8FiUAlg08+oYS9onGFY7Yvm6RsfV3aiETBsfl96W9qY+ysCi5TtM/ewEjNiIv2Gm26GBw5TPepYN32qmXtp/fSpjg2PVwcnuWW5KkTJdKGG5icYoo5pBpdiJi3c16Ltn3RXOEypjmwSE1ONJp62WmdK1yCbCZDgxKKdoVzb1iQlXoJGqAgmr+lyy3g" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 02:16:00 volumio sudo[12340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 02:15' Sep 01 02:16:00 volumio sudo[12340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="completed keyexchange" Sep 01 02:16:00 volumio go-librespot[12329]: time="2026-09-01T02:16:00+09:00" level=debug msg="completed challenge" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"