Sep 01 04:07:09 volumio wpa_supplicant[1428]: wlan0: Trying to associate with cc:ba:bd:b9:ee:00 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:07:09 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:07:09 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:07:09 volumio wpa_supplicant[1428]: BSSID cc:ba:bd:b9:ee:00 ignore list count incremented to 2, ignoring for 10 seconds Sep 01 04:07:09 volumio volumio[32320]: info: Received Get System Info Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:07:09 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:07:09 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:07:09 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:07:10 volumio volumio5-onboarding[1592]: time=2026-09-01T04:07:10.691+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:07:22 volumio wpa_supplicant[1428]: wlan0: Trying to associate with cc:ba:bd:b9:ee:00 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:07:22 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:07:22 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:07:22 volumio wpa_supplicant[1428]: BSSID cc:ba:bd:b9:ee:00 ignore list count incremented to 3, ignoring for 60 seconds Sep 01 04:07:23 volumio volumio[32320]: info: Received Get System Info Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:07:23 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:07:23 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:07:23 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:07:24 volumio volumio5-onboarding[1592]: time=2026-09-01T04:07:24.427+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:07:36 volumio wpa_supplicant[1428]: wlan0: Trying to associate with 50:3d:d1:de:cc:48 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:07:36 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:07:36 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:07:37 volumio volumio[32320]: info: Received Get System Info Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:07:37 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:07:37 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:07:37 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:07:37 volumio volumio5-onboarding[1592]: time=2026-09-01T04:07:37.875+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:07:41 volumio go-librespot[408]: time="2026-09-01T04:07:41+08:00" level=error msg="did not receive last pong ack from accesspoint, 266s passed" Sep 01 04:07:41 volumio go-librespot[408]: panic: runtime error: invalid memory address or nil pointer dereference Sep 01 04:07:41 volumio go-librespot[408]: [signal SIGSEGV: segmentation violation code=0x1 addr=0xc pc=0x4f7ef0] Sep 01 04:07:41 volumio go-librespot[408]: goroutine 99 gp=0x219c248 m=7 mp=0x2081008 [running]: Sep 01 04:07:41 volumio go-librespot[408]: panic({0x841d88, 0xfa0250}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/panic.go:802 +0x148 fp=0x205af20 sp=0x205aecc pc=0xa92ec Sep 01 04:07:41 volumio go-librespot[408]: runtime.panicmem(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/panic.go:262 Sep 01 04:07:41 volumio go-librespot[408]: runtime.sigpanic() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/signal_unix.go:925 +0x384 fp=0x205af50 sp=0x205af20 pc=0xabca4 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0x2016d18) Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:380 +0x284 fp=0x205afe4 sp=0x205af54 pc=0x4f7ef0 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap2() Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:277 +0x28 fp=0x205afec sp=0x205afe4 pc=0x4f73c4 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x205afec sp=0x205afec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 64 Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:277 +0x15c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 1 gp=0x2002128 m=nil [select, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24cace0 sp=0x24caccc pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.selectgo(0x24cadf0, 0x21abdbc, 0x0, 0x0, 0x2, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x24cad90 sp=0x24cace0 pc=0x85000 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x22a2240, 0x24cae90) Sep 01 04:07:41 volumio go-librespot[408]: /src/zeroconf/zeroconf.go:300 +0x228 fp=0x24cae38 sp=0x24cad90 pc=0x62f43c Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).withAppPlayer(0x20ce880, {0xa3da1c, 0x1005090}, 0x20ad8e0) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:340 +0x5dc fp=0x24caed0 sp=0x24cae38 pc=0x6bcc60 Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).withCredentials(...) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:209 Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).SpotifyToken(0x20ce880, {0xa3da1c, 0x1005090}, {0x209aff8, 0x7}, {0x2198120, 0x11e}) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:201 +0xc0 fp=0x24caf00 sp=0x24caed0 pc=0x6bc02c Sep 01 04:07:41 volumio go-librespot[408]: main.main() Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:620 +0x660 fp=0x24cafa8 sp=0x24caf00 pc=0x6bf56c Sep 01 04:07:41 volumio go-librespot[408]: runtime.main() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:285 +0x2f0 fp=0x24cafec sp=0x24cafa8 pc=0x6f390 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24cafec sp=0x24cafec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 2 gp=0x20027e8 m=nil [force gc (idle), 3 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97746c, 0xff8fa8, 0x11, 0xa, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x204afd4 sp=0x204afc0 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goparkunlock(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:466 Sep 01 04:07:41 volumio go-librespot[408]: runtime.forcegchelper() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:373 +0xe4 fp=0x204afec sp=0x204afd4 pc=0x6f7f4 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x204afec sp=0x204afec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.init.6 in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:361 +0x1c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 3 gp=0x2002b48 m=nil [GC sweep wait]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97746c, 0xff9850, 0xc, 0x9, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x204b7c4 sp=0x204b7b0 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goparkunlock(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:466 Sep 01 04:07:41 volumio go-librespot[408]: runtime.bgsweep(0x2030050) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgcsweep.go:323 +0x11c fp=0x204b7e4 sp=0x204b7c4 pc=0x5768c Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcenable.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:212 +0x28 fp=0x204b7ec sp=0x204b7e4 pc=0x46c3c Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x204b7ec sp=0x204b7ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcenable in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:212 +0x74 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 4 gp=0x2002c68 m=nil [GC scavenge wait]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97746c, 0xffa170, 0xd, 0xa, 0x2) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x204bfb4 sp=0x204bfa0 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goparkunlock(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:466 Sep 01 04:07:41 volumio go-librespot[408]: runtime.(*scavengerState).park(0xffa170) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x204bfc8 sp=0x204bfb4 pc=0x54a28 Sep 01 04:07:41 volumio go-librespot[408]: runtime.bgscavenge(0x2030050) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x204bfe4 sp=0x204bfc8 pc=0x5516c Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcenable.gowrap2() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:213 +0x28 fp=0x204bfec sp=0x204bfe4 pc=0x46be8 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x204bfec sp=0x204bfec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcenable in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:213 +0xbc Sep 01 04:07:41 volumio go-librespot[408]: goroutine 18 gp=0x2082248 m=nil [GOMAXPROCS updater (idle), 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97746c, 0xff95e8, 0x12, 0xa, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x20467a4 sp=0x2046790 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goparkunlock(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:466 Sep 01 04:07:41 volumio go-librespot[408]: runtime.updateMaxProcsGoroutine() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:6720 +0x110 fp=0x20467ec sp=0x20467a4 pc=0x7f174 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x20467ec sp=0x20467ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.defaultGOMAXPROCSUpdateEnable in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:6708 +0x40 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 19 gp=0x20825a8 m=nil [finalizer wait, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x977314, 0x1005180, 0x10, 0xa, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2046f88 sp=0x2046f74 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.runFinalizers() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mfinal.go:210 +0x110 fp=0x2046fec sp=0x2046f88 pc=0x45888 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2046fec sp=0x2046fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.createfing in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mfinal.go:172 +0x5c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 20 gp=0x2169b08 m=nil [cleanup wait, 4595 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97746c, 0xffa348, 0x2e, 0xa, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x204a7a4 sp=0x204a790 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goparkunlock(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:466 Sep 01 04:07:41 volumio go-librespot[408]: runtime.(*cleanupQueue).dequeue(0xffa2e8) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mcleanup.go:439 +0x12c fp=0x204a7c4 sp=0x204a7a4 pc=0x41cb0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.runCleanups() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mcleanup.go:635 +0x7c fp=0x204a7ec sp=0x204a7c4 pc=0x4284c Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x204a7ec sp=0x204a7ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.(*cleanupQueue).createGs in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mcleanup.go:589 +0x124 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 23 gp=0x219cd88 m=nil [IO wait, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97745c, 0xb57c4010, 0x2, 0x2, 0x5) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x205dcf0 sp=0x205dcdc pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.netpollblock(0xb57c4000, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x205dd08 sp=0x205dcf0 pc=0x675a0 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.runtime_pollWait(0xb57c4000, 0x72) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x205dd1c sp=0x205dd08 pc=0xa8864 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).wait(0x20a5468, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x205dd30 sp=0x205dd1c pc=0x136044 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).waitRead(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*FD).Accept(0x20a5450) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x205dd78 sp=0x205dd30 pc=0x13a800 Sep 01 04:07:41 volumio go-librespot[408]: net.(*netFD).accept(0x20a5450) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x205dde0 sp=0x205dd78 pc=0x1abc28 Sep 01 04:07:41 volumio go-librespot[408]: net.(*TCPListener).accept(0x20b0630) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x205de34 sp=0x205dde0 pc=0x1c3554 Sep 01 04:07:41 volumio go-librespot[408]: net.(*TCPListener).Accept(0x20b0630) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x205de50 sp=0x205de34 pc=0x1c259c Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*onceCloseListener).Accept(0x20700a0) Sep 01 04:07:41 volumio go-librespot[408]: :1 +0x34 fp=0x205de68 sp=0x205de50 pc=0x367f9c Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*Server).Serve(0x220c008, {0xa3d218, 0x20b0630}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x205df00 sp=0x205de68 pc=0x341154 Sep 01 04:07:41 volumio go-librespot[408]: net/http.Serve(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2971 Sep 01 04:07:41 volumio go-librespot[408]: main.(*ConcreteApiServer).serve(0x209e8a0) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/api_server.go:666 +0x974 fp=0x205dfe4 sp=0x205df00 pc=0x6b17bc Sep 01 04:07:41 volumio go-librespot[408]: main.NewApiServer.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/api_server.go:332 +0x28 fp=0x205dfec sp=0x205dfe4 pc=0x6b04f4 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x205dfec sp=0x205dfec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by main.NewApiServer in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/api_server.go:332 +0x310 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 36 gp=0x2288248 m=nil [GC worker (idle), 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x977320, 0x22fa800, 0x1c, 0xa, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2296788 sp=0x2296774 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkWorker(0x24b2280) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x22967e4 sp=0x2296788 pc=0x49f34 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x22967ec sp=0x22967e4 pc=0x49e14 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x22967ec sp=0x22967ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 37 gp=0x2288368 m=nil [GC worker (idle), 148020 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x977320, 0x22faa00, 0x1c, 0xa, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2295f88 sp=0x2295f74 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkWorker(0x24b2280) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2295fe4 sp=0x2295f88 pc=0x49f34 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2295fec sp=0x2295fe4 pc=0x49e14 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2295fec sp=0x2295fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 38 gp=0x2288488 m=nil [GC worker (idle), 2733 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x977320, 0x22fac00, 0x1c, 0xa, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x22d4788 sp=0x22d4774 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkWorker(0x24b2280) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x22d47e4 sp=0x22d4788 pc=0x49f34 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x22d47ec sp=0x22d47e4 pc=0x49e14 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x22d47ec sp=0x22d47ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 39 gp=0x22885a8 m=nil [GC worker (idle), 3 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x977320, 0x22fae00, 0x1c, 0xa, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24d2f88 sp=0x24d2f74 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkWorker(0x24b2280) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x24d2fe4 sp=0x24d2f88 pc=0x49f34 Sep 01 04:07:41 volumio go-librespot[408]: runtime.gcBgMarkStartWorkers.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x24d2fec sp=0x24d2fe4 pc=0x49e14 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24d2fec sp=0x24d2fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by runtime.gcBgMarkStartWorkers in goroutine 34 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 29 gp=0x20030e8 m=nil [chan receive, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9772f4, 0x229c138, 0xe, 0x7, 0x2) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2295778 sp=0x2295764 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv(0x229c100, 0x0, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x22957c0 sp=0x2295778 pc=0x3414c Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv1(0x229c100, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:509 +0x20 fp=0x22957d4 sp=0x22957c0 pc=0x33bcc Sep 01 04:07:41 volumio go-librespot[408]: github.com/godbus/dbus/v5.newConn.func1() Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:303 +0x40 fp=0x22957ec sp=0x22957d4 pc=0x4aa8ec Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x22957ec sp=0x22957ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/godbus/dbus/v5.newConn in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:302 +0x52c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 40 gp=0x219c008 m=nil [IO wait, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97745c, 0xb57c3a10, 0x2, 0x2, 0x5) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24d0cbc sp=0x24d0ca8 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.netpollblock(0xb57c3a00, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x24d0cd4 sp=0x24d0cbc pc=0x675a0 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.runtime_pollWait(0xb57c3a00, 0x72) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x24d0ce8 sp=0x24d0cd4 pc=0xa8864 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).wait(0x21a00b8, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x24d0cfc sp=0x24d0ce8 pc=0x136044 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).waitRead(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*FD).ReadMsg(0x21a00a0, {0x23bc140, 0x10, 0x10}, {0x23e6618, 0x1000, 0x1000}, 0x40000000) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_unix.go:295 +0x2c0 fp=0x24d0d6c sp=0x24d0cfc pc=0x1381bc Sep 01 04:07:41 volumio go-librespot[408]: net.(*netFD).readMsg(0x21a00a0, {0x23bc140, 0x10, 0x10}, {0x23e6618, 0x1000, 0x1000}, 0x40000000) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/fd_posix.go:91 +0x58 fp=0x24d0dc8 sp=0x24d0d6c pc=0x1aa2c8 Sep 01 04:07:41 volumio go-librespot[408]: net.(*UnixConn).readMsg(0x2286350, {0x23bc140, 0x10, 0x10}, {0x23e6618, 0x1000, 0x1000}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/unixsock_posix.go:115 +0x58 fp=0x24d0e28 sp=0x24d0dc8 pc=0x1c9d80 Sep 01 04:07:41 volumio go-librespot[408]: net.(*UnixConn).ReadMsgUnix(0x2286350, {0x23bc140, 0x10, 0x10}, {0x23e6618, 0x1000, 0x1000}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/unixsock.go:143 +0x58 fp=0x24d0e78 sp=0x24d0e28 pc=0x1c820c Sep 01 04:07:41 volumio go-librespot[408]: github.com/godbus/dbus/v5.(*oobReader).Read(0x23e6608, {0x23bc140, 0x10, 0x10}) Sep 01 04:07:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Sep 01 04:07:41 volumio volumio[32320]: info: Connection to go-librespot Websocket closed Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:41 +0x50 fp=0x24d0ec8 sp=0x24d0e78 pc=0x4c2af0 Sep 01 04:07:41 volumio go-librespot[408]: io.ReadAtLeast({0xa39d58, 0x23e6608}, {0x23bc140, 0x10, 0x10}, 0x10) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/io/io.go:335 +0x90 fp=0x24d0ef4 sp=0x24d0ec8 pc=0xee954 Sep 01 04:07:41 volumio go-librespot[408]: io.ReadFull(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/io/io.go:354 Sep 01 04:07:41 volumio go-librespot[408]: github.com/godbus/dbus/v5.(*unixTransport).ReadMessage(0x2398120) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:124 +0x224 fp=0x24d0fa0 sp=0x24d0ef4 pc=0x4c32c4 Sep 01 04:07:41 volumio go-librespot[408]: github.com/godbus/dbus/v5.(*Conn).inWorker(0x20ce600) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:390 +0x44 fp=0x24d0fe4 sp=0x24d0fa0 pc=0x4aaef4 Sep 01 04:07:41 volumio go-librespot[408]: github.com/godbus/dbus/v5.(*Conn).Auth.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x28 fp=0x24d0fec sp=0x24d0fe4 pc=0x4a8318 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24d0fec sp=0x24d0fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/godbus/dbus/v5.(*Conn).Auth in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x77c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 32 gp=0x2003208 m=nil [IO wait, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97745c, 0xb57c3810, 0x2, 0x2, 0x5) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x21a9908 sp=0x21a98f4 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.netpollblock(0xb57c3800, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x21a9920 sp=0x21a9908 pc=0x675a0 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.runtime_pollWait(0xb57c3800, 0x72) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x21a9934 sp=0x21a9920 pc=0xa8864 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).wait(0x21a03d8, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x21a9948 sp=0x21a9934 pc=0x136044 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).waitRead(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*FD).Read(0x21a03c0, {0x21c7000, 0x1000, 0x1000}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_unix.go:165 +0x22c fp=0x21a9990 sp=0x21a9948 pc=0x1371c4 Sep 01 04:07:41 volumio go-librespot[408]: net.(*netFD).Read(0x21a03c0, {0x21c7000, 0x1000, 0x1000}) Sep 01 04:07:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/fd_posix.go:68 +0x38 fp=0x21a99bc sp=0x21a9990 pc=0x1a9e78 Sep 01 04:07:41 volumio go-librespot[408]: net.(*conn).Read(0x2286668, {0x21c7000, 0x1000, 0x1000}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/net.go:196 +0x48 fp=0x21a99e8 sp=0x21a99bc pc=0x1b967c Sep 01 04:07:41 volumio go-librespot[408]: io.(*multiReader).Read(0x2398d50, {0x21c7000, 0x1000, 0x1000}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x21a9a14 sp=0x21a99e8 pc=0xefb88 Sep 01 04:07:41 volumio go-librespot[408]: bufio.(*Reader).fill(0x2014330) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/bufio/bufio.go:113 +0x10c fp=0x21a9a38 sp=0x21a9a14 pc=0x2b6c1c Sep 01 04:07:41 volumio go-librespot[408]: bufio.(*Reader).ReadByte(0x2014330) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/bufio/bufio.go:273 +0x28 fp=0x21a9a44 sp=0x21a9a38 pc=0x2b7498 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.readFrameHeader(0x2014330, {0x210ac38, 0x8, 0x8}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/frame.go:55 +0x68 fp=0x21a9a84 sp=0x21a9a44 pc=0x372a08 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.(*Conn).readFrameHeader(0x210ac08, {0xa3da00, 0x1005090}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:266 +0xd0 fp=0x21a9b08 sp=0x21a9a84 pc=0x375bd4 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.(*Conn).readLoop(0x210ac08, {0xa3da00, 0x1005090}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:185 +0x3c fp=0x21a9bcc sp=0x21a9b08 pc=0x375390 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.(*Conn).reader(0x210ac08, {0xa3da00, 0x1005090}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:381 +0xec fp=0x21a9c50 sp=0x21a9bcc pc=0x376798 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.(*Conn).Reader(...) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:36 Sep 01 04:07:41 volumio go-librespot[408]: github.com/coder/websocket.(*Conn).Read(0x210ac08, {0xa3da00, 0x1005090}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:42 +0x30 fp=0x21a9c78 sp=0x21a9c50 pc=0x374944 Sep 01 04:07:41 volumio go-librespot[408]: main.(*ConcreteApiServer).serve.func17({0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/api_server.go:636 +0x3b4 fp=0x21a9cfc sp=0x21a9c78 pc=0x6b2040 Sep 01 04:07:41 volumio go-librespot[408]: net/http.HandlerFunc.ServeHTTP(0x20341a8, {0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x21a9d0c sp=0x21a9cfc pc=0x33d7d8 Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*ServeMux).ServeHTTP(0x207c000, {0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio systemd[1]: go-librespot-daemon.service: Consumed 3month 1w 3d 12h 33min 42.290s CPU time. Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2861 +0x228 fp=0x21a9d4c sp=0x21a9d0c pc=0x33f6c8 Sep 01 04:07:41 volumio go-librespot[408]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x124 fp=0x21a9d74 sp=0x21a9d4c pc=0x6b19b8 Sep 01 04:07:41 volumio go-librespot[408]: net/http.HandlerFunc.ServeHTTP(0x2010170, {0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x21a9d84 sp=0x21a9d74 pc=0x33d7d8 Sep 01 04:07:41 volumio go-librespot[408]: net/http.serverHandler.ServeHTTP({0x220c008}, {0xa3d2d8, 0x2016798}, 0x2016638) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:3340 +0xe0 fp=0x21a9da0 sp=0x21a9d84 pc=0x35cb44 Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*conn).serve(0x22a23c0, {0xa3da38, 0x20281f8}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2109 +0x794 fp=0x21a9fdc sp=0x21a9da0 pc=0x33b894 Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*Server).Serve.gowrap3() Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:3493 +0x38 fp=0x21a9fec sp=0x21a9fdc pc=0x3415cc Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x21a9fec sp=0x21a9fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by net/http.(*Server).Serve in goroutine 23 Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:3493 +0x42c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 63 gp=0x2003688 m=nil [select, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2297e74 sp=0x2297e60 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.selectgo(0x2297f80, 0x2297f4c, 0x0, 0x0, 0x3, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2297f24 sp=0x2297e74 pc=0x85000 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0x2407a90) Sep 01 04:07:41 volumio go-librespot[408]: /src/player/player.go:215 +0x1f4 fp=0x2297fe4 sp=0x2297f24 pc=0x582954 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /src/player/player.go:197 +0x28 fp=0x2297fec sp=0x2297fe4 pc=0x58253c Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2297fec sp=0x2297fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/player/player.go:197 +0x220 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 64 gp=0x2003b08 m=nil [runnable]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.selectgo(0x21adf70, 0x21adb20, 0x0, 0x0, 0xa, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/select.go:122 +0x14ac fp=0x21ad9e0 sp=0x21ad9e0 pc=0x85860 Sep 01 04:07:41 volumio go-librespot[408]: main.(*AppPlayer).Run(0x228f6d0, {0xa3da1c, 0x1005090}, 0x2340740, 0x2340780) Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/player.go:661 +0x368 fp=0x21adfd4 sp=0x21ad9e0 pc=0x6c5950 Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).withAppPlayer.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:274 +0x48 fp=0x21adfec sp=0x21adfd4 pc=0x6bd9f0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x21adfec sp=0x21adfec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:274 +0x46c Sep 01 04:07:41 volumio go-librespot[408]: goroutine 65 gp=0x2003c28 m=nil [chan receive, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9772f4, 0x2090238, 0xe, 0x7, 0x2) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2298f3c sp=0x2298f28 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv(0x2090200, 0x2298fd0, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2298f84 sp=0x2298f3c pc=0x3414c Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv2(0x2090200, 0x2298fd0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x2298f98 sp=0x2298f84 pc=0x33bf0 Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).withAppPlayer.func1() Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:284 +0x68 fp=0x2298fec sp=0x2298f98 pc=0x6bd918 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2298fec sp=0x2298fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:281 +0x4f8 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 66 gp=0x2003d48 m=nil [chan receive, 167188 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9772f4, 0x20901f8, 0xe, 0x7, 0x2) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2299740 sp=0x229972c pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv(0x20901c0, 0x22997e0, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2299788 sp=0x2299740 pc=0x3414c Sep 01 04:07:41 volumio go-librespot[408]: runtime.chanrecv2(0x20901c0, 0x22997e0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x229979c sp=0x2299788 pc=0x33bf0 Sep 01 04:07:41 volumio go-librespot[408]: main.(*App).withAppPlayer.func2() Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:300 +0x6c fp=0x22997ec sp=0x229979c pc=0x6bd47c Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x22997ec sp=0x22997ec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by main.(*App).withAppPlayer in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/cmd/daemon/main.go:297 +0x598 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 67 gp=0x2003e68 m=nil [IO wait, 5 minutes]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x97745c, 0xb57c3c10, 0x2, 0x2, 0x5) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2299dac sp=0x2299d98 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.netpollblock(0xb57c3c00, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2299dc4 sp=0x2299dac pc=0x675a0 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.runtime_pollWait(0xb57c3c00, 0x72) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2299dd8 sp=0x2299dc4 pc=0xa8864 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).wait(0x21a0068, 0x72, 0x0) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2299dec sp=0x2299dd8 pc=0x136044 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*pollDesc).waitRead(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Sep 01 04:07:41 volumio go-librespot[408]: internal/poll.(*FD).Accept(0x21a0050) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x2299e34 sp=0x2299dec pc=0x13a800 Sep 01 04:07:41 volumio go-librespot[408]: net.(*netFD).accept(0x21a0050) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x2299e9c sp=0x2299e34 pc=0x1abc28 Sep 01 04:07:41 volumio go-librespot[408]: net.(*TCPListener).accept(0x2014060) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x2299ef0 sp=0x2299e9c pc=0x1c3554 Sep 01 04:07:41 volumio go-librespot[408]: net.(*TCPListener).Accept(0x2014060) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x2299f0c sp=0x2299ef0 pc=0x1c259c Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*onceCloseListener).Accept(0x235dda0) Sep 01 04:07:41 volumio go-librespot[408]: :1 +0x34 fp=0x2299f24 sp=0x2299f0c pc=0x367f9c Sep 01 04:07:41 volumio go-librespot[408]: net/http.(*Server).Serve(0x2017608, {0xa3d218, 0x2014060}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x2299fbc sp=0x2299f24 pc=0x341154 Sep 01 04:07:41 volumio go-librespot[408]: net/http.Serve(...) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/net/http/server.go:2971 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Sep 01 04:07:41 volumio go-librespot[408]: /src/zeroconf/zeroconf.go:297 +0x8c fp=0x2299fec sp=0x2299fbc pc=0x62f538 Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2299fec sp=0x2299fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Sep 01 04:07:41 volumio go-librespot[408]: /src/zeroconf/zeroconf.go:297 +0x160 Sep 01 04:07:41 volumio go-librespot[408]: goroutine 7289 gp=0x231ed88 m=nil [select]: Sep 01 04:07:41 volumio go-librespot[408]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24c8d78 sp=0x24c8d64 pc=0xa97c0 Sep 01 04:07:41 volumio go-librespot[408]: runtime.selectgo(0x24c8e7c, 0x24c8e50, 0x0, 0x0, 0x2, 0x1) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x24c8e28 sp=0x24c8d78 pc=0x85000 Sep 01 04:07:41 volumio go-librespot[408]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x24c8ecc, {0xa3c8c0, 0x209e900}, 0x0, {0x0, 0x0}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:112 +0x244 fp=0x24c8ea4 sp=0x24c8e28 pc=0x4eb7bc Sep 01 04:07:41 volumio go-librespot[408]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x24c8f5c, {0xa3c8c0, 0x209e900}, 0x0, {0x0, 0x0}) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x5c fp=0x24c8ed4 sp=0x24c8ea4 pc=0x4eb180 Sep 01 04:07:41 volumio go-librespot[408]: github.com/cenkalti/backoff/v4.RetryNotify(...) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Sep 01 04:07:41 volumio go-librespot[408]: github.com/cenkalti/backoff/v4.Retry(...) Sep 01 04:07:41 volumio go-librespot[408]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0x2016d18) Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:335 +0x434 fp=0x24c8fe4 sp=0x24c8ed4 pc=0x4f7878 Sep 01 04:07:41 volumio go-librespot[408]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect.gowrap1() Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:403 +0x28 fp=0x24c8fec sp=0x24c8fe4 pc=0x4f81cc Sep 01 04:07:41 volumio go-librespot[408]: runtime.goexit({}) Sep 01 04:07:41 volumio go-librespot[408]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24c8fec sp=0x24c8fec pc=0xb0874 Sep 01 04:07:41 volumio go-librespot[408]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect in goroutine 7278 Sep 01 04:07:41 volumio go-librespot[408]: /src/ap/ap.go:403 +0x120 Sep 01 04:07:41 volumio go-librespot[407]: Aborted Sep 01 04:07:44 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:44 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:07:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 04:07:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:44 volumio systemd[1]: go-librespot-daemon.service: Consumed 3month 1w 3d 12h 33min 42.290s CPU time. Sep 01 04:07:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:44 volumio go-librespot[32019]: go-librespot daemon starting... Sep 01 04:07:44 volumio go-librespot[32020]: time="2026-09-01T04:07:44+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:07:44 volumio go-librespot[32020]: time="2026-09-01T04:07:44+08:00" level=debug msg="app state loaded" Sep 01 04:07:44 volumio go-librespot[32020]: time="2026-09-01T04:07:44+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:07:44 volumio go-librespot[32020]: time="2026-09-01T04:07:44+08: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" Sep 01 04:07:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:07:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:47 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:47 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:07:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 04:07:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:47 volumio go-librespot[32042]: go-librespot daemon starting... Sep 01 04:07:47 volumio go-librespot[32043]: time="2026-09-01T04:07:47+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:07:47 volumio go-librespot[32043]: time="2026-09-01T04:07:47+08:00" level=debug msg="app state loaded" Sep 01 04:07:47 volumio go-librespot[32043]: time="2026-09-01T04:07:47+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:07:47 volumio go-librespot[32043]: time="2026-09-01T04:07:47+08: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" Sep 01 04:07:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:07:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:50 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:50 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:07:50 volumio wpa_supplicant[1428]: wlan0: Trying to associate with 50:3d:d1:de:cc:48 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:07:50 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:07:50 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:07:50 volumio wpa_supplicant[1428]: BSSID 50:3d:d1:de:cc:48 ignore list count incremented to 2, ignoring for 10 seconds Sep 01 04:07:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 04:07:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:50 volumio go-librespot[32051]: go-librespot daemon starting... Sep 01 04:07:50 volumio volumio[32320]: info: Received Get System Info Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:07:50 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:07:50 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:07:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:07:50 volumio go-librespot[32052]: time="2026-09-01T04:07:50+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:07:50 volumio go-librespot[32052]: time="2026-09-01T04:07:50+08:00" level=debug msg="app state loaded" Sep 01 04:07:50 volumio go-librespot[32052]: time="2026-09-01T04:07:50+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:07:50 volumio go-librespot[32052]: time="2026-09-01T04:07:50+08: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" Sep 01 04:07:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:07:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:51 volumio volumio5-onboarding[1592]: time=2026-09-01T04:07:51.776+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:07:53 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:53 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:07:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 04:07:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:53 volumio go-librespot[32060]: go-librespot daemon starting... Sep 01 04:07:54 volumio go-librespot[32061]: time="2026-09-01T04:07:54+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:07:54 volumio go-librespot[32061]: time="2026-09-01T04:07:54+08:00" level=debug msg="app state loaded" Sep 01 04:07:54 volumio go-librespot[32061]: time="2026-09-01T04:07:54+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:07:54 volumio go-librespot[32061]: time="2026-09-01T04:07:54+08: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" Sep 01 04:07:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:07:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:56 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:56 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:07:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 01 04:07:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:07:57 volumio go-librespot[32083]: go-librespot daemon starting... Sep 01 04:07:57 volumio go-librespot[32084]: time="2026-09-01T04:07:57+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:07:57 volumio go-librespot[32084]: time="2026-09-01T04:07:57+08:00" level=debug msg="app state loaded" Sep 01 04:07:57 volumio go-librespot[32084]: time="2026-09-01T04:07:57+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:07:57 volumio go-librespot[32084]: time="2026-09-01T04:07:57+08: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" Sep 01 04:07:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:07:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:07:59 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:07:59 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 01 04:08:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:00 volumio go-librespot[32092]: go-librespot daemon starting... Sep 01 04:08:00 volumio go-librespot[32093]: time="2026-09-01T04:08:00+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:00 volumio go-librespot[32093]: time="2026-09-01T04:08:00+08:00" level=debug msg="app state loaded" Sep 01 04:08:00 volumio go-librespot[32093]: time="2026-09-01T04:08:00+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:00 volumio go-librespot[32093]: time="2026-09-01T04:08:00+08: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" Sep 01 04:08:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:02 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:02 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 01 04:08:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:03 volumio go-librespot[32101]: go-librespot daemon starting... Sep 01 04:08:03 volumio go-librespot[32102]: time="2026-09-01T04:08:03+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:03 volumio go-librespot[32102]: time="2026-09-01T04:08:03+08:00" level=debug msg="app state loaded" Sep 01 04:08:03 volumio go-librespot[32102]: time="2026-09-01T04:08:03+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:03 volumio go-librespot[32102]: time="2026-09-01T04:08:03+08: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" Sep 01 04:08:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:03 volumio wpa_supplicant[1428]: wlan0: Trying to associate with 50:3d:d1:de:cc:48 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:08:03 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:08:03 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:08:03 volumio wpa_supplicant[1428]: BSSID 50:3d:d1:de:cc:48 ignore list count incremented to 3, ignoring for 60 seconds Sep 01 04:08:04 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:04 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:04 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:04 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:05 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:05 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:05 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:05.276+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 04:08:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:06 volumio go-librespot[32126]: go-librespot daemon starting... Sep 01 04:08:06 volumio go-librespot[32127]: time="2026-09-01T04:08:06+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:06 volumio go-librespot[32127]: time="2026-09-01T04:08:06+08:00" level=debug msg="app state loaded" Sep 01 04:08:07 volumio go-librespot[32127]: time="2026-09-01T04:08:07+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:07 volumio go-librespot[32127]: time="2026-09-01T04:08:07+08: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" Sep 01 04:08:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:08 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:08 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 01 04:08:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:10 volumio go-librespot[32135]: go-librespot daemon starting... Sep 01 04:08:10 volumio go-librespot[32136]: time="2026-09-01T04:08:10+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:10 volumio go-librespot[32136]: time="2026-09-01T04:08:10+08:00" level=debug msg="app state loaded" Sep 01 04:08:10 volumio go-librespot[32136]: time="2026-09-01T04:08:10+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:10 volumio go-librespot[32136]: time="2026-09-01T04:08:10+08: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" Sep 01 04:08:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:11 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:11 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Sep 01 04:08:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:13 volumio go-librespot[32144]: go-librespot daemon starting... Sep 01 04:08:13 volumio go-librespot[32145]: time="2026-09-01T04:08:13+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:13 volumio go-librespot[32145]: time="2026-09-01T04:08:13+08:00" level=debug msg="app state loaded" Sep 01 04:08:13 volumio go-librespot[32145]: time="2026-09-01T04:08:13+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:13 volumio go-librespot[32145]: time="2026-09-01T04:08:13+08: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" Sep 01 04:08:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:14 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:14 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Sep 01 04:08:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:16 volumio go-librespot[32167]: go-librespot daemon starting... Sep 01 04:08:16 volumio go-librespot[32168]: time="2026-09-01T04:08:16+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:16 volumio go-librespot[32168]: time="2026-09-01T04:08:16+08:00" level=debug msg="app state loaded" Sep 01 04:08:16 volumio go-librespot[32168]: time="2026-09-01T04:08:16+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:16 volumio go-librespot[32168]: time="2026-09-01T04:08:16+08: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" Sep 01 04:08:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:17 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:17 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:17 volumio wpa_supplicant[1428]: wlan0: Trying to associate with cc:ba:bd:b9:ee:00 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:08:17 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:08:17 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:08:18 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:18 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:18 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:18 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:19 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:19.018+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Sep 01 04:08:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:19 volumio go-librespot[32176]: go-librespot daemon starting... Sep 01 04:08:20 volumio go-librespot[32177]: time="2026-09-01T04:08:20+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:20 volumio go-librespot[32177]: time="2026-09-01T04:08:20+08:00" level=debug msg="app state loaded" Sep 01 04:08:20 volumio go-librespot[32177]: time="2026-09-01T04:08:20+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:20 volumio go-librespot[32177]: time="2026-09-01T04:08:20+08: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" Sep 01 04:08:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:20 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:20 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Sep 01 04:08:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:23 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:23 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:23 volumio go-librespot[32185]: go-librespot daemon starting... Sep 01 04:08:23 volumio go-librespot[32186]: time="2026-09-01T04:08:23+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:23 volumio go-librespot[32186]: time="2026-09-01T04:08:23+08:00" level=debug msg="app state loaded" Sep 01 04:08:23 volumio go-librespot[32186]: time="2026-09-01T04:08:23+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:23 volumio go-librespot[32186]: time="2026-09-01T04:08:23+08: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" Sep 01 04:08:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:26 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:26 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Sep 01 04:08:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:26 volumio go-librespot[32208]: go-librespot daemon starting... Sep 01 04:08:26 volumio go-librespot[32209]: time="2026-09-01T04:08:26+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:26 volumio go-librespot[32209]: time="2026-09-01T04:08:26+08:00" level=debug msg="app state loaded" Sep 01 04:08:26 volumio go-librespot[32209]: time="2026-09-01T04:08:26+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:26 volumio go-librespot[32209]: time="2026-09-01T04:08:26+08: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" Sep 01 04:08:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:29 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:29 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Sep 01 04:08:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:29 volumio go-librespot[32217]: go-librespot daemon starting... Sep 01 04:08:29 volumio go-librespot[32218]: time="2026-09-01T04:08:29+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:29 volumio go-librespot[32218]: time="2026-09-01T04:08:29+08:00" level=debug msg="app state loaded" Sep 01 04:08:29 volumio go-librespot[32218]: time="2026-09-01T04:08:29+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:29 volumio go-librespot[32218]: time="2026-09-01T04:08:29+08: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" Sep 01 04:08:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:31 volumio wpa_supplicant[1428]: wlan0: Trying to associate with cc:ba:bd:b9:ee:00 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:08:31 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:08:31 volumio wpa_supplicant[1428]: wlan0: Association request to the driver failed Sep 01 04:08:31 volumio wpa_supplicant[1428]: BSSID cc:ba:bd:b9:ee:00 ignore list count incremented to 2, ignoring for 10 seconds Sep 01 04:08:31 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:31 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:31 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:31 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:32 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:32 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:32 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:32.754+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Sep 01 04:08:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:32 volumio go-librespot[32226]: go-librespot daemon starting... Sep 01 04:08:33 volumio go-librespot[32227]: time="2026-09-01T04:08:33+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:33 volumio go-librespot[32227]: time="2026-09-01T04:08:33+08:00" level=debug msg="app state loaded" Sep 01 04:08:33 volumio go-librespot[32227]: time="2026-09-01T04:08:33+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:33 volumio go-librespot[32227]: time="2026-09-01T04:08:33+08: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" Sep 01 04:08:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:35 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:35 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Sep 01 04:08:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:36 volumio go-librespot[32249]: go-librespot daemon starting... Sep 01 04:08:36 volumio go-librespot[32250]: time="2026-09-01T04:08:36+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:36 volumio go-librespot[32250]: time="2026-09-01T04:08:36+08:00" level=debug msg="app state loaded" Sep 01 04:08:36 volumio go-librespot[32250]: time="2026-09-01T04:08:36+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:36 volumio go-librespot[32250]: time="2026-09-01T04:08:36+08: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" Sep 01 04:08:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:38 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:38 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:38 volumio dhcpcd[800]: wlan0: carrier lost Sep 01 04:08:38 volumio wpa_supplicant[1428]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Sep 01 04:08:38 volumio wpa_supplicant[1428]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=SG Sep 01 04:08:38 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:38 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:38 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:38 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Sep 01 04:08:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:39 volumio go-librespot[32273]: go-librespot daemon starting... Sep 01 04:08:39 volumio go-librespot[32274]: time="2026-09-01T04:08:39+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:39 volumio go-librespot[32274]: time="2026-09-01T04:08:39+08:00" level=debug msg="app state loaded" Sep 01 04:08:39 volumio go-librespot[32274]: time="2026-09-01T04:08:39+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:39 volumio go-librespot[32274]: time="2026-09-01T04:08:39+08: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" Sep 01 04:08:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:39 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:39.865+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:41 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:41 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Sep 01 04:08:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:42 volumio go-librespot[32282]: go-librespot daemon starting... Sep 01 04:08:42 volumio go-librespot[32283]: time="2026-09-01T04:08:42+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:42 volumio go-librespot[32283]: time="2026-09-01T04:08:42+08:00" level=debug msg="app state loaded" Sep 01 04:08:42 volumio go-librespot[32283]: time="2026-09-01T04:08:42+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:42 volumio go-librespot[32283]: time="2026-09-01T04:08:42+08: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" Sep 01 04:08:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: Trying to associate with cc:ba:bd:b9:ee:00 (SSID='Psalms91' freq=2437 MHz) Sep 01 04:08:43 volumio wpa_supplicant[1428]: FT: Invalid key management type (2) Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: Associated with cc:ba:bd:b9:ee:00 Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=SG Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: WPA: Key negotiation completed with cc:ba:bd:b9:ee:00 [PTK=CCMP GTK=CCMP] Sep 01 04:08:43 volumio wpa_supplicant[1428]: wlan0: CTRL-EVENT-CONNECTED - Connection to cc:ba:bd:b9:ee:00 completed [id=0 id_str=] Sep 01 04:08:43 volumio dhcpcd[800]: wlan0: carrier acquired Sep 01 04:08:43 volumio dhcpcd[800]: wlan0: IAID 32:95:23:d0 Sep 01 04:08:44 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:44 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:44 volumio dhcpcd[800]: wlan0: soliciting an IPv6 router Sep 01 04:08:44 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:44 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:44 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:44 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:45 volumio dhcpcd[800]: wlan0: soliciting a DHCP lease Sep 01 04:08:45 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:45.368+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:45 volumio dhcpcd[800]: wlan0: offered 192.168.0.24 from 192.168.0.1 Sep 01 04:08:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Sep 01 04:08:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:45 volumio go-librespot[32293]: go-librespot daemon starting... Sep 01 04:08:46 volumio go-librespot[32294]: time="2026-09-01T04:08:46+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:46 volumio go-librespot[32294]: time="2026-09-01T04:08:46+08:00" level=debug msg="app state loaded" Sep 01 04:08:46 volumio go-librespot[32294]: time="2026-09-01T04:08:46+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:46 volumio go-librespot[32294]: time="2026-09-01T04:08:46+08: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" Sep 01 04:08:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:46 volumio wpa_supplicant[1428]: wlan0: WNM: Disassociation Imminent - Disassociation Timer 0 Sep 01 04:08:46 volumio wpa_supplicant[1428]: wlan0: WNM: Preferred List Available Sep 01 04:08:47 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:47 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:49 volumio dhcpcd[800]: wlan0: probing address 192.168.0.24/24 Sep 01 04:08:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Sep 01 04:08:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:49 volumio go-librespot[32317]: go-librespot daemon starting... Sep 01 04:08:49 volumio go-librespot[32318]: time="2026-09-01T04:08:49+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:49 volumio go-librespot[32318]: time="2026-09-01T04:08:49+08:00" level=debug msg="app state loaded" Sep 01 04:08:49 volumio go-librespot[32318]: time="2026-09-01T04:08:49+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:49 volumio go-librespot[32318]: time="2026-09-01T04:08:49+08: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" Sep 01 04:08:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:49 volumio kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Sep 01 04:08:50 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:50 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:50 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:50 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:50 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:50 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:51 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:51.203+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Sep 01 04:08:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:52 volumio go-librespot[32336]: go-librespot daemon starting... Sep 01 04:08:52 volumio go-librespot[32337]: time="2026-09-01T04:08:52+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:52 volumio go-librespot[32337]: time="2026-09-01T04:08:52+08:00" level=debug msg="app state loaded" Sep 01 04:08:52 volumio go-librespot[32337]: time="2026-09-01T04:08:52+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:52 volumio go-librespot[32337]: time="2026-09-01T04:08:52+08: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" Sep 01 04:08:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:53 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:53 volumio volumio[32320]: info: Error connecting to go-librespot Websocket: AggregateError Sep 01 04:08:53 volumio dhcpcd[800]: wlan0: leased 192.168.0.24 for infinity Sep 01 04:08:53 volumio avahi-daemon[22018]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.24. Sep 01 04:08:53 volumio avahi-daemon[22018]: New relevant interface wlan0.IPv4 for mDNS. Sep 01 04:08:53 volumio avahi-daemon[22018]: Registering new address record for 192.168.0.24 on wlan0.IPv4. Sep 01 04:08:53 volumio dhcpcd[800]: wlan0: adding route to 192.168.0.0/24 Sep 01 04:08:53 volumio dhcpcd[800]: wlan0: adding default route via 192.168.0.1 Sep 01 04:08:53 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Sep 01 04:08:53 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Sep 01 04:08:53 volumio systemd[1]: welcome.service: Deactivated successfully. Sep 01 04:08:53 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Sep 01 04:08:53 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Sep 01 04:08:53 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Sep 01 04:08:53 volumio welcome[32365]: Resolved ip:[1] 192.168.0.24 Sep 01 04:08:53 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Sep 01 04:08:53 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Sep 01 04:08:54 volumio volumio[32320]: info: Received Get System Info Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 04:08:54 volumio volumio[32320]: info: Discovery: Getting this device information Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:54 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 04:08:54 volumio volumio[32320]: info: Discovery: adding 3373ae2e-2e6f-4006-aab9-b3932327dbde Sep 01 04:08:54 volumio volumio[32320]: info: Discovery: Found device Volumio Sep 01 04:08:54 volumio volumio[32320]: info: CoreCommandRouter::volumioGetState Sep 01 04:08:54 volumio volumio[32320]: info: CorePlayQueue::getTrack 0 Sep 01 04:08:55 volumio ntpd[1029]: IO: Listen normally on 8 wlan0 192.168.0.24:123 Sep 01 04:08:55 volumio ntpd[1029]: IO: new interface(s) found: waking up resolver Sep 01 04:08:55 volumio volumio5-onboarding[1592]: time=2026-09-01T04:08:55.143+08:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 04:08:55 volumio wpa_supplicant[1428]: wlan0: WNM: Disassociation Imminent - Disassociation Timer 0 Sep 01 04:08:55 volumio wpa_supplicant[1428]: wlan0: WNM: Preferred List Available Sep 01 04:08:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Sep 01 04:08:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 04:08:55 volumio go-librespot[32382]: go-librespot daemon starting... Sep 01 04:08:55 volumio go-librespot[32383]: time="2026-09-01T04:08:55+08:00" level=info msg="running go-librespot 0.7.1" Sep 01 04:08:55 volumio go-librespot[32383]: time="2026-09-01T04:08:55+08:00" level=debug msg="app state loaded" Sep 01 04:08:55 volumio go-librespot[32383]: time="2026-09-01T04:08:55+08:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 04:08:56 volumio volumio[32320]: info: Volumio Network Manager: Network status updated: 2 Sep 01 04:08:56 volumio volumio[32320]: info: Initializing connection to go-librespot Websocket Sep 01 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08:00" level=debug msg="new websocket client" Sep 01 04:08:56 volumio volumio[32320]: info: Connection to go-librespot Websocket established Sep 01 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08: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 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08: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 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08: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 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08:00" level=info msg="zeroconf server listening on port 39677" Sep 01 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Sep 01 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08:00" level=debug msg="obtained new client token: AAEo5PJYcpaUpig4tdegFRCKUbssJcRFi2xNxcYNjd1GiuJTFWQVJwjlfOD37wlj2MWXuXeKS7FrTLsqg68EkbfGDjWCcEuOvbm5Zj3YDnRlIlbUmuwtZE0/osxon6sLFysviGdrlMUyrvnyv/A1IxHKw5+4Lw/8vPt9ueekPK8w/vvcUa2hdhcmhVQ5zv3l54o6aWq4dRKXGu2HDkxYExgVyrE7zmXueCtHaq/8cRrEuD+s6nrjNq1x" Sep 01 04:08:56 volumio go-librespot[32383]: time="2026-09-01T04:08:56+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Sep 01 04:08:57 volumio go-librespot[32383]: time="2026-09-01T04:08:57+08:00" level=debug msg="completed keyexchange" Sep 01 04:08:57 volumio go-librespot[32383]: time="2026-09-01T04:08:57+08:00" level=debug msg="completed challenge" Sep 01 04:08:57 volumio go-librespot[32383]: time="2026-09-01T04:08:57+08:00" level=info msg="authenticated AP" username="xy***22" Sep 01 04:08:58 volumio go-librespot[32383]: time="2026-09-01T04:08:58+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 04:08:58 volumio volumio[32320]: info: Connection to go-librespot Websocket closed Sep 01 04:08:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 04:08:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 04:08:58 volumio kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Sep 01 04:08:59 volumio volumio[32320]: info: Getting Spotify volume Sep 01 04:08:59 volumio volumio[32320]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 04:08:59 volumio volumio[32320]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 04:08:59 volumio volumio[32320]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 04:08:59 volumio volumio[32320]: errno: -111, Sep 01 04:08:59 volumio volumio[32320]: code: 'ECONNREFUSED', Sep 01 04:08:59 volumio volumio[32320]: syscall: 'connect', Sep 01 04:08:59 volumio volumio[32320]: address: '127.0.0.1', Sep 01 04:08:59 volumio volumio[32320]: port: 9879, Sep 01 04:08:59 volumio volumio[32320]: response: undefined Sep 01 04:08:59 volumio volumio[32320]: } Sep 01 04:08:59 volumio volumio[32320]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 04:08:59 volumio sudo[32462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 04:07' Sep 01 04:08:59 volumio sudo[32462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"