Aug 26 22:26:25 volumio go-librespot[2356]: time="2026-08-26T22:26:25+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Aug 26 22:26:28 volumio go-librespot[2356]: time="2026-08-26T22:26:28+01:00" level=error msg="did not receive last pong ack from accesspoint, 268s passed" Aug 26 22:26:28 volumio go-librespot[2356]: panic: runtime error: invalid memory address or nil pointer dereference Aug 26 22:26:28 volumio go-librespot[2356]: [signal SIGSEGV: segmentation violation code=0x1 addr=0xc pc=0x4f6f14] Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 332380 gp=0x272dd48 m=5 mp=0x2480008 [running]: Aug 26 22:26:28 volumio go-librespot[2356]: panic({0x82e098, 0xf78250}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/panic.go:802 +0x148 fp=0x276bf20 sp=0x276becc pc=0xa92ec Aug 26 22:26:28 volumio go-librespot[2356]: runtime.panicmem(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/panic.go:262 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.sigpanic() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/signal_unix.go:925 +0x384 fp=0x276bf50 sp=0x276bf20 pc=0xabca4 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0x263c638) Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:380 +0x284 fp=0x276bfe4 sp=0x276bf54 pc=0x4f6f14 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap2() Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:277 +0x28 fp=0x276bfec sp=0x276bfe4 pc=0x4f63e8 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x276bfec sp=0x276bfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 332372 Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:277 +0x15c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 1 gp=0x2402128 m=nil [select, 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x276ece8 sp=0x276ecd4 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x276edf8, 0x2675dc4, 0x0, 0x0, 0x2, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x276ed98 sp=0x276ece8 pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x24a8180, 0x276ee90) Aug 26 22:26:28 volumio go-librespot[2356]: /src/zeroconf/zeroconf.go:283 +0x21c fp=0x276ee3c sp=0x276ed98 pc=0x61db0c Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).withAppPlayer(0x262e480, {0xa260ac, 0xfdcff0}, 0x2613360) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:340 +0x580 fp=0x276eed0 sp=0x276ee3c pc=0x6ab088 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).withCredentials(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:209 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).SpotifyToken(0x262e480, {0xa260ac, 0xfdcff0}, {0x2610f20, 0xa}, {0x2650140, 0x127}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:201 +0xc0 fp=0x276ef00 sp=0x276eed0 pc=0x6aa4b0 Aug 26 22:26:28 volumio go-librespot[2356]: main.main() Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:593 +0x660 fp=0x276efa8 sp=0x276ef00 pc=0x6ad58c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.main() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:285 +0x2f0 fp=0x276efec sp=0x276efa8 pc=0x6f390 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x276efec sp=0x276efec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 2 gp=0x24027e8 m=nil [force gc (idle), 2 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960edc, 0xfd0f08, 0x11, 0xa, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2448fd4 sp=0x2448fc0 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goparkunlock(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:466 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.forcegchelper() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:373 +0xe4 fp=0x2448fec sp=0x2448fd4 pc=0x6f7f4 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2448fec sp=0x2448fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.init.6 in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:361 +0x1c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 3 gp=0x2402b48 m=nil [GC sweep wait]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960edc, 0xfd17b0, 0xc, 0x9, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24497c4 sp=0x24497b0 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goparkunlock(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:466 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.bgsweep(0x242e050) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgcsweep.go:323 +0x11c fp=0x24497e4 sp=0x24497c4 pc=0x5768c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcenable.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:212 +0x28 fp=0x24497ec sp=0x24497e4 pc=0x46c3c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24497ec sp=0x24497ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcenable in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:212 +0x74 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 4 gp=0x2402c68 m=nil [GC scavenge wait]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960edc, 0xfd20d0, 0xd, 0xa, 0x2) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2449fb4 sp=0x2449fa0 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goparkunlock(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:466 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.(*scavengerState).park(0xfd20d0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x2449fc8 sp=0x2449fb4 pc=0x54a28 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.bgscavenge(0x242e050) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x2449fe4 sp=0x2449fc8 pc=0x5516c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcenable.gowrap2() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:213 +0x28 fp=0x2449fec sp=0x2449fe4 pc=0x46be8 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2449fec sp=0x2449fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcenable in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:213 +0xbc Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 5 gp=0x2402fc8 m=nil [GOMAXPROCS updater (idle), 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960edc, 0xfd1548, 0x12, 0xa, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x244a7a4 sp=0x244a790 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goparkunlock(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:466 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.updateMaxProcsGoroutine() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:6720 +0x110 fp=0x244a7ec sp=0x244a7a4 pc=0x7f174 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x244a7ec sp=0x244a7ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.defaultGOMAXPROCSUpdateEnable in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:6708 +0x40 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 6 gp=0x2403328 m=nil [finalizer wait, 72632 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d84, 0xfdd0e0, 0x10, 0xa, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x244af88 sp=0x244af74 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.runFinalizers() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mfinal.go:210 +0x110 fp=0x244afec sp=0x244af88 pc=0x45888 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x244afec sp=0x244afec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.createfing in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mfinal.go:172 +0x5c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 18 gp=0x262c248 m=nil [cleanup wait, 580 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960edc, 0xfd22a8, 0x2e, 0xa, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x24447a4 sp=0x2444790 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goparkunlock(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:466 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.(*cleanupQueue).dequeue(0xfd2248) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mcleanup.go:439 +0x12c fp=0x24447c4 sp=0x24447a4 pc=0x41cb0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.runCleanups() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mcleanup.go:635 +0x7c fp=0x24447ec sp=0x24447c4 pc=0x4284c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x24447ec sp=0x24447ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.(*cleanupQueue).createGs in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mcleanup.go:589 +0x124 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 21 gp=0x262d208 m=nil [IO wait, 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960ecc, 0xb47c3e10, 0x2, 0x2, 0x5) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2456cf0 sp=0x2456cdc pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.netpollblock(0xb47c3e00, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x2456d08 sp=0x2456cf0 pc=0x675a0 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.runtime_pollWait(0xb47c3e00, 0x72) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2456d1c sp=0x2456d08 pc=0xa8864 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).wait(0x260d1e8, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2456d30 sp=0x2456d1c pc=0x134df4 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).waitRead(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*FD).Accept(0x260d1d0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x2456d78 sp=0x2456d30 pc=0x1395b0 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*netFD).accept(0x260d1d0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x2456de0 sp=0x2456d78 pc=0x1aa9d8 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*TCPListener).accept(0x2614450) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x2456e34 sp=0x2456de0 pc=0x1c2304 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*TCPListener).Accept(0x2614450) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x2456e50 sp=0x2456e34 pc=0x1c134c Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*onceCloseListener).Accept(0x24a4080) Aug 26 22:26:28 volumio go-librespot[2356]: :1 +0x34 fp=0x2456e68 sp=0x2456e50 pc=0x367710 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Server).Serve(0x24b4008, {0xa258a8, 0x2614450}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x2456f00 sp=0x2456e68 pc=0x3408c8 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.Serve(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2971 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*ConcreteApiServer).serve(0x26164e0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/api_server.go:666 +0x974 fp=0x2456fe4 sp=0x2456f00 pc=0x69fdac Aug 26 22:26:28 volumio go-librespot[2356]: main.NewApiServer.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/api_server.go:332 +0x28 fp=0x2456fec sp=0x2456fe4 pc=0x69eae4 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2456fec sp=0x2456fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by main.NewApiServer in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/api_server.go:332 +0x310 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 34 gp=0x262d328 m=nil [IO wait]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960ecc, 0xb47c3810, 0x2, 0x2, 0x5) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x245de88 sp=0x245de74 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.netpollblock(0xb47c3800, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x245dea0 sp=0x245de88 pc=0x675a0 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.runtime_pollWait(0xb47c3800, 0x72) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x245deb4 sp=0x245dea0 pc=0xa8864 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).wait(0x250a248, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x245dec8 sp=0x245deb4 pc=0x134df4 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).waitRead(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*FD).RawRead(0x250a230, 0x2614270) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_unix.go:710 +0x154 fp=0x245def4 sp=0x245dec8 pc=0x13a168 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*rawConn).Read(0x2498340, 0x2614270) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x245df14 sp=0x245def4 pc=0x1bc9b4 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x27841d0, 0x2614240, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/internal/socket/rawconn_msg.go:27 +0x140 fp=0x245df44 sp=0x245df14 pc=0x5b7e28 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/internal/socket/socket.go:247 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x26fa0c8, {0x275a000, 0x10000, 0x10000}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/ipv4/payload_cmsg.go:31 +0x1a0 fp=0x245df9c sp=0x245df44 pc=0x5bbb1c Aug 26 22:26:28 volumio go-librespot[2356]: github.com/grandcat/zeroconf.(*Server).recv4(0x27da440, 0x26fa0c0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xdc fp=0x245dfe0 sp=0x245df9c pc=0x618bf8 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x245dfec sp=0x245dfe0 pc=0x6188c8 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x245dfec sp=0x245dfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 27 Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 9 gp=0x25de7e8 m=nil [GC worker (idle), 2 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d90, 0x25fa400, 0x1c, 0xa, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2770f88 sp=0x2770f74 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkWorker(0x2800ec0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2770fe4 sp=0x2770f88 pc=0x49f34 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkStartWorkers.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2770fec sp=0x2770fe4 pc=0x49e14 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2770fec sp=0x2770fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcBgMarkStartWorkers in goroutine 25 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 10 gp=0x25de908 m=nil [GC worker (idle), 50372 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d90, 0x25fa600, 0x1c, 0xa, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2950788 sp=0x2950774 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkWorker(0x2800ec0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x29507e4 sp=0x2950788 pc=0x49f34 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkStartWorkers.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x29507ec sp=0x29507e4 pc=0x49e14 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x29507ec sp=0x29507ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcBgMarkStartWorkers in goroutine 25 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 11 gp=0x25dea28 m=nil [GC worker (idle), 21340 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d90, 0x25fa800, 0x1c, 0xa, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2981788 sp=0x2981774 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkWorker(0x2800ec0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x29817e4 sp=0x2981788 pc=0x49f34 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkStartWorkers.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x29817ec sp=0x29817e4 pc=0x49e14 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x29817ec sp=0x29817ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcBgMarkStartWorkers in goroutine 25 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 12 gp=0x25deb48 m=nil [GC worker (idle), 50372 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d90, 0x25faa00, 0x1c, 0xa, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2982f88 sp=0x2982f74 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkWorker(0x2800ec0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x2982fe4 sp=0x2982f88 pc=0x49f34 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gcBgMarkStartWorkers.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x2982fec sp=0x2982fe4 pc=0x49e14 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2982fec sp=0x2982fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by runtime.gcBgMarkStartWorkers in goroutine 25 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 95 gp=0x24827e8 m=nil [IO wait, 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960ecc, 0xb3bcb810, 0x2, 0x2, 0x5) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x26718d4 sp=0x26718c0 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.netpollblock(0xb3bcb800, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x26718ec sp=0x26718d4 pc=0x675a0 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.runtime_pollWait(0xb3bcb800, 0x72) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x2671900 sp=0x26718ec pc=0xa8864 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).wait(0x292ce78, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2671914 sp=0x2671900 pc=0x134df4 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).waitRead(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*FD).Read(0x292ce60, {0x2790000, 0x1000, 0x1000}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_unix.go:165 +0x22c fp=0x267195c sp=0x2671914 pc=0x135f74 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*netFD).Read(0x292ce60, {0x2790000, 0x1000, 0x1000}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/fd_posix.go:68 +0x38 fp=0x2671988 sp=0x267195c pc=0x1a8c28 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*conn).Read(0x277e1b0, {0x2790000, 0x1000, 0x1000}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/net.go:196 +0x48 fp=0x26719b4 sp=0x2671988 pc=0x1b842c Aug 26 22:26:28 volumio go-librespot[2356]: io.(*multiReader).Read(0x26121e0, {0x2790000, 0x1000, 0x1000}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x26719e0 sp=0x26719b4 pc=0xef364 Aug 26 22:26:28 volumio go-librespot[2356]: bufio.(*Reader).fill(0x26a02a0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/bufio/bufio.go:113 +0x10c fp=0x2671a04 sp=0x26719e0 pc=0x2b6390 Aug 26 22:26:28 volumio go-librespot[2356]: bufio.(*Reader).ReadByte(0x26a02a0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/bufio/bufio.go:273 +0x28 fp=0x2671a10 sp=0x2671a04 pc=0x2b6c0c Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.readFrameHeader(0x26a02a0, {0x264a67c, 0x8, 0x8}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/frame.go:55 +0x68 fp=0x2671a50 sp=0x2671a10 pc=0x498164 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x264a648, {0xa26090, 0xfdcff0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/read.go:235 +0xb4 fp=0x2671b10 sp=0x2671a50 pc=0x49b01c Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).readLoop(0x264a648, {0xa26090, 0xfdcff0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/read.go:193 +0x3c fp=0x2671bd4 sp=0x2671b10 pc=0x49ab08 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).reader(0x264a648, {0xa26090, 0xfdcff0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/read.go:355 +0xec fp=0x2671c58 sp=0x2671bd4 pc=0x49bc20 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).Reader(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/read.go:39 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).Read(0x264a648, {0xa26090, 0xfdcff0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/read.go:47 +0x30 fp=0x2671c80 sp=0x2671c58 pc=0x49a0a0 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*ConcreteApiServer).serve.func17({0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/api_server.go:636 +0x3b0 fp=0x2671cfc sp=0x2671c80 pc=0x6a062c Aug 26 22:26:28 volumio go-librespot[2356]: net/http.HandlerFunc.ServeHTTP(0x2498188, {0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x2671d0c sp=0x2671cfc pc=0x33cf4c Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*ServeMux).ServeHTTP(0x2490000, {0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2861 +0x228 fp=0x2671d4c sp=0x2671d0c pc=0x33ee3c Aug 26 22:26:28 volumio go-librespot[2356]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x124 fp=0x2671d74 sp=0x2671d4c pc=0x69ffa8 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.HandlerFunc.ServeHTTP(0x2494140, {0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x2671d84 sp=0x2671d74 pc=0x33cf4c Aug 26 22:26:28 volumio go-librespot[2356]: net/http.serverHandler.ServeHTTP({0x24b4008}, {0xa25968, 0x263c168}, 0x2550588) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:3340 +0xe0 fp=0x2671da0 sp=0x2671d84 pc=0x35c2b8 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*conn).serve(0x28e5aa0, {0xa260c8, 0x24a21e0}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2109 +0x794 fp=0x2671fdc sp=0x2671da0 pc=0x33b008 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Server).Serve.gowrap3() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:3493 +0x38 fp=0x2671fec sp=0x2671fdc pc=0x340d40 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2671fec sp=0x2671fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by net/http.(*Server).Serve in goroutine 21 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:3493 +0x42c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 35 gp=0x25de6c8 m=nil [IO wait, 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960ecc, 0xb47c3610, 0x2, 0x2, 0x5) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x268fe60 sp=0x268fe4c pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.netpollblock(0xb47c3600, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x268fe78 sp=0x268fe60 pc=0x675a0 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.runtime_pollWait(0xb47c3600, 0x72) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x268fe8c sp=0x268fe78 pc=0xa8864 Aug 26 22:26:28 volumio volumio[2164]: info: Connection to go-librespot Websocket closed Aug 26 22:26:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).wait(0x250a298, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x268fea0 sp=0x268fe8c pc=0x134df4 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).waitRead(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*FD).RawRead(0x250a280, 0x26a0030) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_unix.go:710 +0x154 fp=0x268fecc sp=0x268fea0 pc=0x13a168 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*rawConn).Read(0x2498368, 0x26a0030) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x268feec sp=0x268fecc pc=0x1bc9b4 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x27841e0, 0x26a0000, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/internal/socket/rawconn_msg.go:27 +0x140 fp=0x268ff1c sp=0x268feec pc=0x5b7e28 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/internal/socket/socket.go:247 Aug 26 22:26:28 volumio go-librespot[2356]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x26fa0f8, {0x2690000, 0x10000, 0x10000}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/golang.org/x/net@v0.48.0/ipv6/payload_cmsg.go:31 +0x188 fp=0x268ff9c sp=0x268ff1c pc=0x5bf588 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/grandcat/zeroconf.(*Server).recv6(0x27da440, 0x26fa0f0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xdc fp=0x268ffe0 sp=0x268ff9c pc=0x618ddc Aug 26 22:26:28 volumio go-librespot[2356]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x268ffec sp=0x268ffe0 pc=0x61886c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x268ffec sp=0x268ffec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 27 Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 47 gp=0x25deea8 m=nil [chan receive, 72676 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d64, 0x26660f8, 0xe, 0x7, 0x2) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2857f3c sp=0x2857f28 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.chanrecv(0x26660c0, 0x2857fd0, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x2857f84 sp=0x2857f3c pc=0x3414c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.chanrecv2(0x26660c0, 0x2857fd0) Aug 26 22:26:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x2857f98 sp=0x2857f84 pc=0x33bf0 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).withAppPlayer.func1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:284 +0x68 fp=0x2857fec sp=0x2857f98 pc=0x6abd40 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2857fec sp=0x2857fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by main.(*App).withAppPlayer in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:281 +0x49c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 48 gp=0x25defc8 m=nil [chan receive, 72634 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960d64, 0x26660b8, 0xe, 0x7, 0x2) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x268cf40 sp=0x268cf2c pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.chanrecv(0x2666080, 0x2673fe0, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x268cf88 sp=0x268cf40 pc=0x3414c Aug 26 22:26:28 volumio go-librespot[2356]: runtime.chanrecv2(0x2666080, 0x2673fe0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x268cf9c sp=0x268cf88 pc=0x33bf0 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).withAppPlayer.func2() Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:300 +0x6c fp=0x268cfec sp=0x268cf9c pc=0x6ab8a4 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x268cfec sp=0x268cfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by main.(*App).withAppPlayer in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:297 +0x53c Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 49 gp=0x25df0e8 m=nil [IO wait, 422 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960ecc, 0xb47c3a10, 0x2, 0x2, 0x5) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x28505ac sp=0x2850598 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.netpollblock(0xb47c3a00, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x28505c4 sp=0x28505ac pc=0x675a0 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.runtime_pollWait(0xb47c3a00, 0x72) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x28505d8 sp=0x28505c4 pc=0xa8864 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).wait(0x250a1f8, 0x72, 0x0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x28505ec sp=0x28505d8 pc=0x134df4 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*pollDesc).waitRead(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Aug 26 22:26:28 volumio go-librespot[2356]: internal/poll.(*FD).Accept(0x250a1e0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x2850634 sp=0x28505ec pc=0x1395b0 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*netFD).accept(0x250a1e0) Aug 26 22:26:28 volumio systemd[1]: go-librespot-daemon.service: Consumed 1month 3d 23h 11min 9.124s CPU time. Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x285069c sp=0x2850634 pc=0x1aa9d8 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*TCPListener).accept(0x26fa060) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x28506f0 sp=0x285069c pc=0x1c2304 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*TCPListener).Accept(0x26fa060) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x285070c sp=0x28506f0 pc=0x1c134c Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*onceCloseListener).Accept(0x24a4300) Aug 26 22:26:28 volumio go-librespot[2356]: :1 +0x34 fp=0x2850724 sp=0x285070c pc=0x367710 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Server).Serve(0x26fc378, {0xa258a8, 0x26fa060}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x28507bc sp=0x2850724 pc=0x3408c8 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.Serve(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/server.go:2971 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Aug 26 22:26:28 volumio go-librespot[2356]: /src/zeroconf/zeroconf.go:280 +0x8c fp=0x28507ec sp=0x28507bc pc=0x61dc08 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x28507ec sp=0x28507ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Aug 26 22:26:28 volumio go-librespot[2356]: /src/zeroconf/zeroconf.go:280 +0x154 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 105 gp=0x25dfc28 m=nil [select, 72634 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2851694 sp=0x2851680 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x28517a8, 0x285176c, 0x0, 0x0, 0x5, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2851744 sp=0x2851694 pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x264a648) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/conn.go:180 +0x144 fp=0x28517e4 sp=0x2851744 pc=0x494d20 Aug 26 22:26:28 volumio go-librespot[2356]: nhooyr.io/websocket.newConn.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/conn.go:140 +0x28 fp=0x28517ec sp=0x28517e4 pc=0x4949b0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x28517ec sp=0x28517ec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by nhooyr.io/websocket.newConn in goroutine 95 Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.17/conn.go:140 +0x578 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 333591 gp=0x26d1e68 m=nil [select]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x276f86c sp=0x276f858 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x276f9dc, 0x276f948, 0x0, 0x0, 0x2, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x276f91c sp=0x276f86c pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).lookupIPAddr(0xfd1660, {0xa2611c, 0x27e4820}, {0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/lookup.go:343 +0x394 fp=0x276fa24 sp=0x276f91c pc=0x1b68b0 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).internetAddrList(0xfd1660, {0xa2611c, 0x27e4820}, {0x903a4e, 0x3}, {0x26a28e0, 0x19}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/ipsock.go:289 +0x6b0 fp=0x276fab8 sp=0x276fa24 pc=0x1b486c Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).resolveAddrList(0xfd1660, {0xa2611c, 0x27e4820}, {0x903e50, 0x4}, {0x903a4e, 0x3}, {0x26a28e0, 0x19}, {0x0, ...}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/dial.go:353 +0x510 fp=0x276fb40 sp=0x276fab8 pc=0x19f1a8 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Dialer).DialContext(0x263ee00, {0xa260e4, 0x26145d0}, {0x903a4e, 0x3}, {0x26a28e0, 0x19}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/dial.go:560 +0x43c fp=0x276fc3c sp=0x276fb40 pc=0x1a00e4 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Dialer).DialContext-fm({0xa260e4, 0x26145d0}, {0x903a4e, 0x3}, {0x26a28e0, 0x19}) Aug 26 22:26:28 volumio go-librespot[2356]: :1 +0x58 fp=0x276fc6c sp=0x276fc3c pc=0x368914 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).dial(0xf812a8, {0xa260e4, 0x26145d0}, {0x903a4e, 0x3}, {0x26a28e0, 0x19}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1278 +0x158 fp=0x276fcac sp=0x276fc6c pc=0x3506d4 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).dialConn(0xf812a8, {0xa260e4, 0x26145d0}, {{}, 0x0, {0x917af4, 0x5}, {0x26a28e0, 0x19}, 0x0}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1783 +0x6a4 fp=0x276ff60 sp=0x276fcac pc=0x3530b0 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).dialConnFor(0xf812a8, 0x26c2000) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1618 +0x80 fp=0x276ffc4 sp=0x276ff60 pc=0x351e80 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).startDialConnForLocked.func1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1600 +0x3c fp=0x276ffec sp=0x276ffc4 pc=0x351d08 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x276ffec sp=0x276ffec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by net/http.(*Transport).startDialConnForLocked in goroutine 333658 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1599 +0x134 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 333658 gp=0x27f5b08 m=nil [select]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x245c50c sp=0x245c4f8 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x245c66c, 0x245c5e4, 0x0, 0x0, 0x2, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x245c5bc sp=0x245c50c pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).getConn(0xf812a8, 0x2614480, {{}, 0x0, {0x917af4, 0x5}, {0x26a28e0, 0x19}, 0x0}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:1523 +0x370 fp=0x245c6b8 sp=0x245c5bc pc=0x351440 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).roundTrip(0xf812a8, 0x24b4428) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/transport.go:685 +0x978 fp=0x245c7a4 sp=0x245c6b8 pc=0x34d528 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Transport).RoundTrip(0xf812a8, 0x24b4428) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/roundtrip.go:33 +0x2c fp=0x245c7bc sp=0x245c7a4 pc=0x35ba84 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.send(0x24b4168, {0xa21b28, 0xf812a8}, {0xc29bf467e7c4bbdc, 0xf7df056d2423d, 0xfd1e68}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/client.go:259 +0x53c fp=0x245c8e8 sp=0x245c7bc pc=0x2ed3ec Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Client).send(0x2603240, 0x24b4168, {0xc29bf467e7c4bbdc, 0xf7df056d2423d, 0xfd1e68}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/client.go:180 +0x98 fp=0x245c92c sp=0x245c8e8 pc=0x2eccd8 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Client).do(0x2603240, 0x24b4168) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/client.go:729 +0x9a8 fp=0x245ca3c sp=0x245c92c pc=0x2ef340 Aug 26 22:26:28 volumio go-librespot[2356]: net/http.(*Client).Do(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/http/client.go:587 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/apresolve.(*ApResolver).fetchUrls(0x26142a0, {0xa2611c, 0x27e4370}, {0x245ccb0, 0x1, 0x1}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/apresolve/resolve.go:83 +0x4d0 fp=0x245cc74 sp=0x245ca3c pc=0x597990 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/apresolve.(*ApResolver).get(0x26142a0, {0xa2611c, 0x27e4370}, {0x907726, 0xb}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/apresolve/resolve.go:126 +0x84 fp=0x245ccbc sp=0x245cc74 pc=0x598514 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/apresolve.(*ApResolver).getFunc.func1({0xa2611c, 0x27e4370}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/apresolve/resolve.go:157 +0x90 fp=0x245cd08 sp=0x245ccbc pc=0x598918 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).init(0x263c638, {0xa260ac, 0xfdcff0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:94 +0x26c fp=0x245cd80 sp=0x245cd08 pc=0x4f4938 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).connect(0x263c638, {0xa260ac, 0xfdcff0}, 0x2492f00) Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:205 +0xd4 fp=0x245cde4 sp=0x245cd80 pc=0x4f5a7c Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect(0x263c638) Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:394 +0xcc fp=0x245ce0c sp=0x245cde4 pc=0x4f703c Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect-fm() Aug 26 22:26:28 volumio go-librespot[2356]: :1 +0x28 fp=0x245ce1c sp=0x245ce0c pc=0x4fb294 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.Operation.withEmptyData.func1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:18 +0x1c fp=0x245ce28 sp=0x245ce1c pc=0x4ea1ec Aug 26 22:26:28 volumio go-librespot[2356]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x245cecc, {0xa24f50, 0x27cc000}, 0x0, {0x0, 0x0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:88 +0xcc fp=0x245cea4 sp=0x245ce28 pc=0x4ea668 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x245cf5c, {0xa24f50, 0x27cc000}, 0x0, {0x0, 0x0}) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x5c fp=0x245ced4 sp=0x245cea4 pc=0x4ea1a4 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/cenkalti/backoff/v4.RetryNotify(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/cenkalti/backoff/v4.Retry(...) Aug 26 22:26:28 volumio go-librespot[2356]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0x263c638) Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:335 +0x434 fp=0x245cfe4 sp=0x245ced4 pc=0x4f689c Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:403 +0x28 fp=0x245cfec sp=0x245cfe4 pc=0x4f71f0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x245cfec sp=0x245cfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect in goroutine 333589 Aug 26 22:26:28 volumio go-librespot[2356]: /src/ap/ap.go:403 +0x120 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 332371 gp=0x28ad328 m=nil [select, 72634 minutes]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x2860e74 sp=0x2860e60 pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x2860f80, 0x2860f4c, 0x0, 0x0, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x2860f24 sp=0x2860e74 pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0x284c320) Aug 26 22:26:28 volumio go-librespot[2356]: /src/player/player.go:215 +0x1f4 fp=0x2860fe4 sp=0x2860f24 pc=0x5818e0 Aug 26 22:26:28 volumio go-librespot[2356]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/player/player.go:197 +0x28 fp=0x2860fec sp=0x2860fe4 pc=0x5814c8 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x2860fec sp=0x2860fec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 48 Aug 26 22:26:28 volumio go-librespot[2356]: /src/player/player.go:197 +0x220 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 332372 gp=0x29eaea8 m=nil [runnable]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x291df70, 0x291db20, 0x0, 0x0, 0xa, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:122 +0x14ac fp=0x291d9e0 sp=0x291d9e0 pc=0x85860 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*AppPlayer).Run(0x27e4870, {0xa260ac, 0xfdcff0}, 0x249f080, 0x249f0c0) Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/player.go:661 +0x368 fp=0x291dfd4 sp=0x291d9e0 pc=0x6b3970 Aug 26 22:26:28 volumio go-librespot[2356]: main.(*App).withAppPlayer.func2.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:328 +0x48 fp=0x291dfec sp=0x291dfd4 pc=0x6abcac Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x291dfec sp=0x291dfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by main.(*App).withAppPlayer.func2 in goroutine 48 Aug 26 22:26:28 volumio go-librespot[2356]: /src/cmd/daemon/main.go:328 +0x2f0 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 333593 gp=0x2a76008 m=4 mp=0x244d808 [syscall]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.cgocall(0x74cab0, 0x288fefc) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/cgocall.go:167 +0x50 fp=0x288fee4 sp=0x288fecc pc=0xa628c Aug 26 22:26:28 volumio go-librespot[2356]: net._C2func_getaddrinfo(0x26a6150, 0x0, 0x2778340, 0x277e2e0) Aug 26 22:26:28 volumio go-librespot[2356]: _cgo_gotypes.go:105 +0x44 fp=0x288fef8 sp=0x288fee4 pc=0x1c97c8 Aug 26 22:26:28 volumio go-librespot[2356]: net._C_getaddrinfo.func1(...) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix_cgo.go:84 Aug 26 22:26:28 volumio go-librespot[2356]: net._C_getaddrinfo(0x26a6150, 0x0, 0x2778340, 0x277e2e0) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix_cgo.go:84 +0x80 fp=0x288ff18 sp=0x288fef8 pc=0x1c9a8c Aug 26 22:26:28 volumio go-librespot[2356]: net.cgoLookupHostIP({0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:174 +0x1f4 fp=0x288ff8c sp=0x288ff18 pc=0x19bd90 Aug 26 22:26:28 volumio go-librespot[2356]: net.cgoLookupIP.func1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:229 +0x34 fp=0x288ffb4 sp=0x288ff8c pc=0x19c3b4 Aug 26 22:26:28 volumio go-librespot[2356]: net.doBlockingWithCtx[...].func1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:67 +0x54 fp=0x288ffec sp=0x288ffb4 pc=0x1cc878 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x288ffec sp=0x288ffec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by net.doBlockingWithCtx[...] in goroutine 333592 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:64 +0x204 Aug 26 22:26:28 volumio go-librespot[2356]: goroutine 333592 gp=0x2bb2128 m=nil [select]: Aug 26 22:26:28 volumio go-librespot[2356]: runtime.gopark(0x960f10, 0x0, 0x9, 0x3, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x276cb60 sp=0x276cb4c pc=0xa97c0 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.selectgo(0x276cc68, 0x276cc38, 0x0, 0x0, 0x2, 0x1) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x276cc10 sp=0x276cb60 pc=0x85000 Aug 26 22:26:28 volumio go-librespot[2356]: net.doBlockingWithCtx[...]({0xa260e4, 0x2614a50}, {0x26a28e0, 0x15}, 0x24c42b8) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:71 +0x280 fp=0x276cc90 sp=0x276cc10 pc=0x1cc630 Aug 26 22:26:28 volumio go-librespot[2356]: net.cgoLookupIP({0xa260e4, 0x2614a50}, {0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/cgo_unix.go:228 +0x98 fp=0x276ccc0 sp=0x276cc90 pc=0x19c334 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).lookupIP(0xfd1660, {0xa260e4, 0x2614a50}, {0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/lookup_unix.go:64 +0x90 fp=0x276cefc sp=0x276ccc0 pc=0x1b7a0c Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).lookupIP-fm({0xa260e4, 0x2614a50}, {0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: :1 +0x58 fp=0x276cf30 sp=0x276cefc pc=0x1d2324 Aug 26 22:26:28 volumio go-librespot[2356]: net.init.func1({0xa260e4, 0x2614a50}, 0x277e2c8, {0x903a4e, 0x3}, {0x26a28e0, 0x15}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/hook.go:21 +0x4c fp=0x276cf60 sp=0x276cf30 pc=0x1999a8 Aug 26 22:26:28 volumio go-librespot[2356]: net.(*Resolver).lookupIPAddr.func1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/net/lookup.go:335 +0x58 fp=0x276cf9c sp=0x276cf60 pc=0x1b724c Aug 26 22:26:28 volumio go-librespot[2356]: internal/singleflight.(*Group).doCall(0xfd1668, 0x2614a80, {0x26a2900, 0x19}, 0x2778320) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/singleflight/singleflight.go:93 +0x1c fp=0x276cfd4 sp=0x276cf9c pc=0x197c48 Aug 26 22:26:28 volumio go-librespot[2356]: internal/singleflight.(*Group).DoChan.gowrap1() Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/singleflight/singleflight.go:86 +0x48 fp=0x276cfec sp=0x276cfd4 pc=0x197c00 Aug 26 22:26:28 volumio go-librespot[2356]: runtime.goexit({}) Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x276cfec sp=0x276cfec pc=0xb0874 Aug 26 22:26:28 volumio go-librespot[2356]: created by internal/singleflight.(*Group).DoChan in goroutine 333591 Aug 26 22:26:28 volumio go-librespot[2356]: /usr/local/go/src/internal/singleflight/singleflight.go:86 +0x304 Aug 26 22:26:28 volumio go-librespot[2355]: Aborted Aug 26 22:26:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 22:26:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:26:31 volumio systemd[1]: go-librespot-daemon.service: Consumed 1month 3d 23h 11min 9.124s CPU time. Aug 26 22:26:31 volumio volumio[2164]: info: Initializing connection to go-librespot Websocket Aug 26 22:26:31 volumio volumio[2164]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 22:26:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:26:31 volumio go-librespot[19694]: go-librespot daemon starting... Aug 26 22:26:31 volumio go-librespot[19695]: time="2026-08-26T22:26:31+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:26:31 volumio go-librespot[19695]: time="2026-08-26T22:26:31+01:00" level=debug msg="app state loaded" Aug 26 22:26:31 volumio go-librespot[19695]: time="2026-08-26T22:26:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:26:34 volumio volumio[2164]: info: Initializing connection to go-librespot Websocket Aug 26 22:26:34 volumio go-librespot[19695]: time="2026-08-26T22:26:34+01:00" level=debug msg="new websocket client" Aug 26 22:26:34 volumio volumio[2164]: info: Connection to go-librespot Websocket established Aug 26 22:26:37 volumio volumio[2164]: info: Getting Spotify volume Aug 26 22:26:37 volumio volumio[2164]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 26 22:26:37 volumio volumio[2164]: info: CoreCommandRouter::volumioGetState Aug 26 22:26:59 volumio go-librespot[19695]: time="2026-08-26T22:26:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 26 22:26:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:26:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:26:59 volumio volumio[2164]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:26:59 volumio volumio[2164]: Error: socket hang up Aug 26 22:26:59 volumio volumio[2164]: at connResetException (node:internal/errors:720:14) Aug 26 22:26:59 volumio volumio[2164]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 26 22:26:59 volumio volumio[2164]: at Socket.emit (node:events:526:35) Aug 26 22:26:59 volumio volumio[2164]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 26 22:26:59 volumio volumio[2164]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 26 22:26:59 volumio volumio[2164]: code: 'ECONNRESET', Aug 26 22:26:59 volumio volumio[2164]: response: undefined Aug 26 22:26:59 volumio volumio[2164]: } Aug 26 22:26:59 volumio volumio[2164]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:26:59 volumio sudo[19763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 22:25' Aug 26 22:26:59 volumio sudo[19763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:26:59 volumio sudo[19763]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:00 volumio volumio5-onboarding[1529]: time=2026-08-26T22:27:00.126+01:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 26 22:27:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:00 volumio volumio-remote-updater[715]: [2026-08-26 22:27:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 26 22:27:00 volumio volumio-remote-updater[715]: [2026-08-26 22:27:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 26 22:27:00 volumio volumio5-onboarding[1529]: time=2026-08-26T22:27:00.129+01:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 22:27:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 26 22:27:00 volumio systemd[1]: volumio.service: Consumed 6h 43min 29.645s CPU time. Aug 26 22:27:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 26 22:27:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Aug 26 22:27:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Aug 26 22:27:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 26 22:27:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 26 22:27:00 volumio systemd[1]: volumio.service: Consumed 6h 43min 29.645s CPU time. Aug 26 22:27:00 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Aug 26 22:27:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Aug 26 22:27:01 volumio volumio5-onboarding[1529]: time=2026-08-26T22:27:01.131+01:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 22:27:01 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:01 volumio volumio[19804]: info: ----- Volumio3 ---- Aug 26 22:27:01 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:01 volumio volumio[19804]: info: ----- System startup ---- Aug 26 22:27:01 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:02 volumio volumio[19804]: info: MYVOLUMIO Environment detected Aug 26 22:27:02 volumio volumio[19804]: info: Plugin folders cleanup Aug 26 22:27:02 volumio volumio[19804]: info: Scanning into folder /volumio/app/plugins/ Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category audio_interface Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category miscellanea Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category music_service Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category plugins.json Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category system_controller Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category user_interface Aug 26 22:27:02 volumio volumio[19804]: info: Scanning into folder /data/plugins/ Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category music_service Aug 26 22:27:02 volumio volumio[19804]: info: Scanning category user_interface Aug 26 22:27:02 volumio volumio[19804]: info: Plugin folders cleanup completed Aug 26 22:27:02 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:02 volumio volumio[19804]: info: ----- Core plugins startup ---- Aug 26 22:27:02 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugins from folder /volumio/app/plugins/ Aug 26 22:27:02 volumio volumio[19804]: info: Adding plugin upnp to MyMusic Plugins Aug 26 22:27:02 volumio volumio[19804]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 26 22:27:02 volumio volumio[19804]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugins from folder /data/plugins/ Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "system"... Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "appearance"... Aug 26 22:27:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 22:27:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:02 volumio go-librespot[19831]: go-librespot daemon starting... Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=debug msg="app state loaded" Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "network"... Aug 26 22:27:02 volumio volumio[19804]: info: Refreshing Cached IP Addresses Aug 26 22:27:02 volumio sudo[19842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 22:27:02 volumio sudo[19842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:02 volumio sudo[19844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "services"... Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "volumio5onboarding"... Aug 26 22:27:02 volumio sudo[19844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:02 volumio sudo[19844]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "alsa_controller"... Aug 26 22:27:02 volumio sudo[19853]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 26 22:27:02 volumio sudo[19853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:02 volumio sudo[19842]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:02 volumio volumio[19804]: warn: Unable to locate the audio output device CA CXA81 2.0. Please configure a valid output device. Aug 26 22:27:02 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "wizard"... Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "networkfs"... Aug 26 22:27:02 volumio volumio[19804]: info: Starting Udev Watcher for removable devices Aug 26 22:27:02 volumio volumio[19804]: info: Ignoring mount for partition: boot Aug 26 22:27:02 volumio volumio[19804]: info: Ignoring mount for partition: volumio Aug 26 22:27:02 volumio volumio[19804]: info: Ignoring mount for partition: volumio_data Aug 26 22:27:02 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "volumio_command_line_client"... Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "upnp"... Aug 26 22:27:02 volumio volumio[19804]: info: [1787779622842] Starting Upmpd Daemon Aug 26 22:27:02 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "my_music"... Aug 26 22:27:02 volumio volumio[19804]: info: Loading plugin "mpd"... Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 22:27:02 volumio go-librespot[19832]: time="2026-08-26T22:27:02+01:00" level=info msg="zeroconf server listening on port 46331" Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "upnp_browser"... Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=debug msg="obtained new client token: AAG0bocwL42WiC83cvsdTAHJrd5HFdRXbQFWAHcYdmi/XdTYZYGu4VL28AULilri2b9+dTY0nagIwMACVYeHphRarCwLKUgxw13m/8ieldD0Dz/hiG2bg9qNpzWH7UGnZHhX0Ndii5cDWj1Vkesm/GGmbsmfI52OECHzIYKZjBmfI+v/GMCiryCmi8yfreX1Iduk6VUDBUZ8zp7329u+cH4EUZHwYp8FgGCY4NL2l1rZpyApZPyeQaY=" Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=debug msg="completed challenge" Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:03 volumio volumio[19804]: info: Starting UPNP Browser Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "alarm-clock"... Aug 26 22:27:03 volumio go-librespot[19832]: time="2026-08-26T22:27:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "airplay_emulation"... Aug 26 22:27:03 volumio volumio[19804]: info: Starting Shairport Sync Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "last_100"... Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "webradio"... Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "i2s_dacs"... Aug 26 22:27:03 volumio volumio[19804]: info: I2S DAC not set, start Auto-detection Aug 26 22:27:03 volumio volumio[19804]: info: Loading plugin "volumiodiscovery"... Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** For more information see Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 22:27:03 volumio node[19804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 22:27:03 volumio volumio[19804]: *** WARNING *** For more information see Aug 26 22:27:03 volumio node[19804]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 22:27:03 volumio node[19804]: *** WARNING *** For more information see Aug 26 22:27:03 volumio node[19804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 22:27:03 volumio node[19804]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 22:27:03 volumio node[19804]: *** WARNING *** For more information see Aug 26 22:27:03 volumio volumio[19804]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 26 22:27:04 volumio volumio[19804]: info: Discovery: Started advertising with name: Volumio Aug 26 22:27:04 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "spop"... Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "outputs"... Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "albumart"... Aug 26 22:27:04 volumio volumio[19804]: info: Plugin example_plugin is not enabled Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "inputs"... Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "updater_comm"... Aug 26 22:27:04 volumio volumio[19804]: info: Plugin mpdemulation is not enabled Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "rest_api"... Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "websocket"... Aug 26 22:27:04 volumio volumio[19804]: info: Starting Socket.io Server version 1.7.4 Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "motherearthradio"... Aug 26 22:27:04 volumio volumio[19804]: info: Applying required configuration parameters for plugin motherearthradio Aug 26 22:27:04 volumio volumio[19804]: info: [1787779624817] [MotherEarth] API delay: 5 Aug 26 22:27:04 volumio volumio[19804]: info: Loading plugin "Systeminfo"... Aug 26 22:27:04 volumio volumio[19874]: Forking 3 albumart workers Aug 26 22:27:05 volumio volumio[19804]: info: Loading i18n strings for locale en Aug 26 22:27:05 volumio volumio[19804]: Updating browse sources language Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:05 volumio volumio-remote-updater[715]: [2026-08-26 22:27:05] [connect] Successful connection Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::initPlayerControls Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: Express server listening on port 3000 Aug 26 22:27:05 volumio volumio[19804]: [Metrics] WebUI: 3s 848.84ms Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::resetVolumioState Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::getcurrentVolume Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::pushState Aug 26 22:27:05 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioPushState Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: Volumio Network Manager: Network status updated: 2 Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 26 22:27:05 volumio volumio-remote-updater[715]: [2026-08-26 22:27:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787779625 101 Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::setRepeat true single undefined Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::pushState Aug 26 22:27:05 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioPushState Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::setRandom null Aug 26 22:27:05 volumio volumio[19804]: info: CoreStateMachine::pushState Aug 26 22:27:05 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioPushState Aug 26 22:27:05 volumio volumio[19804]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 26 22:27:05 volumio volumio[19804]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Aug 26 22:27:05 volumio volumio[19804]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: info: Setting Device type: Raspberry PI Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: info: Completed loading Core Plugins Aug 26 22:27:05 volumio volumio[19804]: info: Preparing to generate the ALSA configuration file Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:05 volumio volumio[19804]: info: Asound.conf file unchanged, so no further update is needed Aug 26 22:27:05 volumio volumio[19804]: info: Output device has changed, restarting MPD Aug 26 22:27:05 volumio volumio[19804]: info: Output device has changed, restarting Shairport Sync Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:05 volumio sudo[19927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 22:27:05 volumio sudo[19927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:05 volumio sudo[19927]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:05 volumio volumio[19804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 22:27:05 volumio volumio[19804]: info: ___________ START PLUGINS ___________ Aug 26 22:27:05 volumio sudo[19931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 22:27:05 volumio sudo[19931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:05 volumio volumio[19804]: info: ControllerMpd::onStart: Initializing MPD Aug 26 22:27:05 volumio volumio[19804]: info: Creating MPD Configuration file Aug 26 22:27:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 26 22:27:05 volumio sudo[19937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 22:27:05 volumio sudo[19939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 22:27:05 volumio sudo[19939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:05 volumio sudo[19937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:05 volumio sudo[19941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 22:27:05 volumio sudo[19939]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:05 volumio sudo[19941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 22:27:05 volumio volumio[19804]: info: [1787779625670] CoreMusicLibrary::Adding element Media Servers Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:05 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 26 22:27:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 22:27:05 volumio systemd[1]: mpd.service: Consumed 50.384s CPU time. Aug 26 22:27:05 volumio volumio[19804]: info: UPNP Browser: Client initialized successfully Aug 26 22:27:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 26 22:27:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 22:27:05 volumio volumio[19804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 22:27:05 volumio volumio[19804]: info: [1787779625762] CoreMusicLibrary::Adding element Last_100 Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 22:27:05 volumio volumio[19804]: info: [1787779625767] CoreMusicLibrary::Adding element Webradio Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 22:27:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 22:27:05 volumio sudo[19937]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:05 volumio volumio[19804]: info: Initializing BBC Radios Aug 26 22:27:05 volumio volumio[19884]: Starting albumart workers Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:05 volumio volumio[19804]: info: Creating Spotify config file Aug 26 22:27:05 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:05 volumio sudo[19955]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 22:27:05 volumio sudo[19955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 22:27:05 volumio sudo[19955]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:06 volumio volumio[19885]: Starting albumart workers Aug 26 22:27:06 volumio volumio[19886]: Starting albumart workers Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 22:27:06 volumio volumio[19804]: info: [1787779626317] CoreMusicLibrary::Adding element Mother Earth Radio Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:06 volumio volumio[19804]: Cannot find translation for source Mother Earth Radio Aug 26 22:27:06 volumio volumio[19804]: info: Volumio Calling Home Aug 26 22:27:06 volumio sudo[19853]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:06 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:06 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 22:27:06 volumio volumio[19804]: info: Discovery: adding ff761a39-3af5-4238-b9f0-91528703e739 Aug 26 22:27:06 volumio volumio[19804]: info: Discovery: Found device Volumio Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::volumioGetState Aug 26 22:27:06 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:06 volumio volumio[19804]: info: Discovery: this is already registered, ff761a39-3af5-4238-b9f0-91528703e739 Aug 26 22:27:06 volumio volumio[19804]: info: Discovery: Found device Volumio Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::volumioGetState Aug 26 22:27:06 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:06 volumio volumio[19804]: info: MPD Permissions set Aug 26 22:27:06 volumio volumio[19804]: info: MPD Permissions set Aug 26 22:27:06 volumio volumio[19804]: info: Spotify config file written Aug 26 22:27:06 volumio volumio[19804]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 26 22:27:06 volumio sudo[19995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 22:27:06 volumio sudo[19995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:27:06 volumio volumio[19804]: info: No need to fix Spotify hosts Aug 26 22:27:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:06 volumio go-librespot[20007]: go-librespot daemon starting... Aug 26 22:27:06 volumio sudo[19995]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:06 volumio go-librespot[20008]: time="2026-08-26T22:27:06+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:06 volumio go-librespot[20008]: time="2026-08-26T22:27:06+01:00" level=debug msg="app state loaded" Aug 26 22:27:06 volumio go-librespot[20008]: time="2026-08-26T22:27:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:06 volumio volumio[19804]: info: Received Get System Info Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 22:27:06 volumio volumio[19804]: info: Discovery: Getting this device information Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::volumioGetState Aug 26 22:27:06 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 22:27:06 volumio volumio[19804]: info: Volumio called home Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 22:27:06 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 22:27:06 volumio volumio[19804]: info: Starting Shairport Sync Aug 26 22:27:06 volumio volumio[19804]: info: Starting Shairport Sync Aug 26 22:27:06 volumio volumio[19804]: info: Starting Shairport Sync Aug 26 22:27:06 volumio sudo[20019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:27:06 volumio sudo[20019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:07 volumio sudo[20017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:27:07 volumio sudo[20017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:07 volumio sudo[20021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:27:07 volumio sudo[20021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 22:27:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 22:27:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:27:07 volumio systemd[1]: shairport-sync.service: Consumed 2h 58min 43.494s CPU time. Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=info msg="zeroconf server listening on port 39421" Aug 26 22:27:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:27:07 volumio sudo[20019]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:07 volumio sudo[20017]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 22:27:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 22:27:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:27:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:27:07 volumio sudo[20021]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="obtained new client token: AAGbNlBU+kBXvaKg7g849LA68iAkmrTYtQqOnZL/XJ3MY8A1OMY0okvQZIBKb23xHopZAl/TztSJOBI76D4C49/j/EywdQcIIXbnaUalJjSVTeokkRfJUb5iXu1i6S7U8MOohyOp4wQsI/LPc/v/OEVyznYJalbMOxROzkU7QN9emLd9rFtO2oKulXMT5xBVis8+7pvHzXKhAb7Yl0AiFlkGXrKYbvnbD8YQwGnQVwEtm+O6+c6t0xU=" Aug 26 22:27:07 volumio volumio[19804]: info: Shairport-Sync Started Aug 26 22:27:07 volumio volumio[19804]: Error adding Membership: Error: addMembership EINVAL Aug 26 22:27:07 volumio volumio[19804]: info: Shairport-Sync Started Aug 26 22:27:07 volumio volumio[19804]: info: New Spotify access tokenBQATsRFjXB... Aug 26 22:27:07 volumio volumio[19804]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 26 22:27:07 volumio volumio[19804]: info: Shairport-Sync Started Aug 26 22:27:07 volumio volumio[19804]: info: CoreCommandRouter::volumioGetState Aug 26 22:27:07 volumio volumio[19804]: info: CorePlayQueue::getTrack 0 Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=debug msg="completed challenge" Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:07 volumio volumio[19804]: SPOTIFY: User informations: {"account_id":"hRxk35F8po","country":"IN","display_name":"burnicscar","email":"ckaggarwal@protonmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/burnicscar"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/burnicscar","id":"burnicscar","images":[],"product":"premium","type":"user","uri":"spotify:user:burnicscar"} Aug 26 22:27:07 volumio volumio[19804]: info: Spotify Successfully logged in Aug 26 22:27:07 volumio volumio[19804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 22:27:07 volumio volumio[19804]: info: [1787779627411] CoreMusicLibrary::Adding element Spotify Aug 26 22:27:07 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:27:07 volumio volumio[19804]: Cannot find translation for source Mother Earth Radio Aug 26 22:27:07 volumio volumio[19804]: Cannot find translation for source Spotify Aug 26 22:27:07 volumio go-librespot[20008]: time="2026-08-26T22:27:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:07 volumio mpd[19970]: 2026-08-26T22:27:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 22:27:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 22:27:07 volumio sudo[19931]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:07 volumio sudo[19941]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:07 volumio volumio[19804]: info: Completed starting Core Plugins Aug 26 22:27:07 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:07 volumio volumio[19804]: info: ----- MyVolumio plugins startup ---- Aug 26 22:27:07 volumio volumio[19804]: info: ------------------------------------------- Aug 26 22:27:07 volumio volumio[19804]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 22:27:07 volumio volumio[19804]: error: updateQueue error: null Aug 26 22:27:07 volumio volumio[19804]: error: updateQueue error: null Aug 26 22:27:07 volumio volumio[19804]: info: MPD running with PID19970 Aug 26 22:27:07 volumio volumio[19804]: ,establishing connection Aug 26 22:27:07 volumio volumio[19804]: error: updateQueue error: null Aug 26 22:27:07 volumio volumio5-onboarding[1529]: time=2026-08-26T22:27:07.930+01:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 26 22:27:09 volumio volumio[19804]: info: go-librespot daemon successfully initialized Aug 26 22:27:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 26 22:27:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:10 volumio go-librespot[20050]: go-librespot daemon starting... Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="app state loaded" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=info msg="zeroconf server listening on port 43681" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="obtained new client token: AAH83eg+YziP7jG/2+Ku3nMvW287OIDJmOHGdWDqlTDu7gAIaedGJwSFu29poLGsrd2Mz4oc9mT1ZfJJSh/iz9ui7b2Flf29GeoHXwKpl4biX2QnRgHenGxU0g7bG0TWM4fIgzZvXIc7T+BiFZ4zCy1E5potUonVUOb52RS0fzdgVNOc6pfWYFzsqiuo7pQFUTxWtQJjx/qz0TU2RMqjogY9s6ZEA593LWVpqRDR4YNHRpcdVFA87TEStA==" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=debug msg="completed challenge" Aug 26 22:27:10 volumio go-librespot[20051]: time="2026-08-26T22:27:10+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:11 volumio go-librespot[20051]: time="2026-08-26T22:27:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:12 volumio volumio[19804]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 22:27:12 volumio sudo[20075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 22:27:12 volumio sudo[20075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:12 volumio sudo[20075]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:12 volumio sudo[20078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 22:27:12 volumio sudo[20078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:12 volumio sudo[20078]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:12 volumio sudo[20081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 26 22:27:12 volumio sudo[20081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:12 volumio sudo[20081]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:12 volumio volumio[19804]: info: Upmpdcli Daemon Started Aug 26 22:27:12 volumio volumio[19804]: info: Initializing connection to go-librespot Websocket Aug 26 22:27:12 volumio volumio[19804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 22:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 26 22:27:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:14 volumio go-librespot[20084]: go-librespot daemon starting... Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="app state loaded" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=info msg="zeroconf server listening on port 41321" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="obtained new client token: AAHYOqO57BHhfpwl/0coOG0rBaX6AHwWWwqAkP8ND3REtCLo2tp9G05oIZ+NxnW28IGwLnIYsntQv9RTz9X9eOsy16nWiXeic5ghXV/+undsLADuG9UfPeGjqp6cfDkruOF8Ls9sydMf2e0cH+SO2EAVcnauC51byN472+IssPq0vAmy2f74UiDiZnAXfLaJT2ArYBtMDnoRDP/m5yyWiCd38YaInjQ3yVKNzOPUOmlwRwns2e6bJCI3YQ==" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=debug msg="completed challenge" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:14 volumio go-librespot[20085]: time="2026-08-26T22:27:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:15 volumio volumio[19804]: info: Initializing connection to go-librespot Websocket Aug 26 22:27:15 volumio volumio[19804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 22:27:16 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:16 volumio volumio[19804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:27:16 volumio volumio[19804]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 22:27:16 volumio volumio[19804]: info: MyVolumio login type: Token Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 22:27:16 volumio volumio[19804]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 22:27:17 volumio volumio[19804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 22:27:17 volumio volumio[19804]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 22:27:17 volumio volumio[19804]: info: Streaming services startup Aug 26 22:27:17 volumio volumio[19804]: info: Starting Streaming Daemon Aug 26 22:27:17 volumio sudo[20095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 22:27:17 volumio sudo[20095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:17 volumio volumio[19804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 22:27:17 volumio sudo[20095]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:17 volumio volumio[19804]: error: Cannot start Volumio Streaming Daemon Aug 26 22:27:17 volumio volumio[19804]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 22:27:17 volumio volumio[19804]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 22:27:17 volumio volumio[19804]: error: MyVolumio Custom Token format not valid, refreshing it Aug 26 22:27:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 26 22:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:18 volumio go-librespot[20102]: go-librespot daemon starting... Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="app state loaded" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=info msg="zeroconf server listening on port 43843" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="obtained new client token: AAGvWEAuiiE9xS4cxVqf5WMCilrpxfI1IZocUd886JY7FpZG5Ngo0ulQKY6SOnOw3d+Z7Xz+DLXcDCl0FiaOZ6fDOmJKotHHEoe8aqf6WidC/pg4iGizZMnYhf1ZnrMNtK+DCEUEBEQ9GXd9oGzQB39jVJoGLFB3uBDTOFNgIeAwm9hqsHAaprvn/HibRDDBrjkr2Zr6IxmmwIoylyS6Ua2kra3yPy3z9VKJNcrNfhJaBQGf5ChXaJFHHg==" Aug 26 22:27:18 volumio volumio[19804]: info: MyVolumio login type: Token Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=debug msg="completed challenge" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:18 volumio go-librespot[20103]: time="2026-08-26T22:27:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:18 volumio volumio[19804]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 26 22:27:18 volumio volumio[19804]: info: Initializing connection to go-librespot Websocket Aug 26 22:27:18 volumio volumio[19804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 22:27:19 volumio volumio[19804]: info: MyVolumio token set successfully Aug 26 22:27:19 volumio volumio[19804]: info: MYVOLUMIO: Adding device Aug 26 22:27:19 volumio volumio[19804]: info: MYVOLUMIO: Evaluating Server Aug 26 22:27:20 volumio volumio[19804]: info: MyVolumio status changed Aug 26 22:27:20 volumio volumio[19804]: info: Streaming services startup Aug 26 22:27:20 volumio volumio[19804]: info: Starting Streaming Daemon Aug 26 22:27:20 volumio volumio[19804]: info: Removing browser output: myVolumio user plan is not superstar Aug 26 22:27:20 volumio volumio[19804]: info: Removing audio output: Aug 26 22:27:20 volumio volumio[19804]: info: Stoppping Tunnel 1 Aug 26 22:27:20 volumio sudo[20132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 22:27:20 volumio sudo[20132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:20 volumio sudo[20134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 26 22:27:20 volumio sudo[20134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:27:20 volumio sudo[20132]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:20 volumio volumio[19804]: error: Cannot start Volumio Streaming Daemon Aug 26 22:27:20 volumio volumio[19804]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 22:27:20 volumio volumio[19804]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:27:20 volumio sudo[20134]: pam_unix(sudo:session): session closed for user root Aug 26 22:27:20 volumio volumio[19804]: info: Remote SSH Stopped Aug 26 22:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 26 22:27:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:27:21 volumio go-librespot[20137]: go-librespot daemon starting... Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=info msg="running go-librespot 0.6.2" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=debug msg="app state loaded" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:27:21 volumio volumio[19804]: info: Initializing connection to go-librespot Websocket Aug 26 22:27:21 volumio volumio[19804]: info: Connection to go-librespot Websocket established Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=debug msg="new websocket client" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:27:21 volumio go-librespot[20138]: time="2026-08-26T22:27:21+01:00" level=info msg="zeroconf server listening on port 41181" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=debug msg="obtained new client token: AAHHzGwy0/kcuTV6R7aF/j7cS3pytUB9C9EhxlcvqzUw9MkjN1RsQIR3fdT1bd0L+9HxzFF6OSztUCbKYRB2hKzw0oK9CV3Diy4JEKzXSyvtGzN5z4TWjyQS+bZ3JbT7Q3rwICXNqQdyms1Z78NYjFw/8aKZWF2pE9ZkcPE6f9J8+1qsFrZNJkN+LBiBcsL+PHCdXWzG9Dx/f5Uwt5OSdc4aSUp1ALdh0IO5q30BKIsOYXqmaas11Lg=" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=debug msg="completed keyexchange" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=debug msg="completed challenge" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=info msg="authenticated AP" username="bu******ar" Aug 26 22:27:22 volumio go-librespot[20138]: time="2026-08-26T22:27:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:27:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:27:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:27:22 volumio volumio[19804]: info: Connection to go-librespot Websocket closed Aug 26 22:27:24 volumio volumio[19804]: info: Getting Spotify volume Aug 26 22:27:24 volumio volumio[19804]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:27:24 volumio volumio[19804]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 22:27:24 volumio volumio[19804]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 22:27:24 volumio volumio[19804]: errno: -111, Aug 26 22:27:24 volumio volumio[19804]: code: 'ECONNREFUSED', Aug 26 22:27:24 volumio volumio[19804]: syscall: 'connect', Aug 26 22:27:24 volumio volumio[19804]: address: '127.0.0.1', Aug 26 22:27:24 volumio volumio[19804]: port: 9879, Aug 26 22:27:24 volumio volumio[19804]: response: undefined Aug 26 22:27:24 volumio volumio[19804]: } Aug 26 22:27:24 volumio volumio[19804]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:27:25 volumio sudo[20175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 22:26' Aug 26 22:27:25 volumio sudo[20175]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"