Apr 11 14:15:03 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:03 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:03 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:03 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:03 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:03.646+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:03 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:03.648+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:04 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:04.560+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:04 hudba go-librespot[3298412]: time="2026-04-11T14:15:04+02:00" level=error msg="did not receive last pong from dealer, 300s passed" Apr 11 14:15:04 hudba go-librespot[3298412]: time="2026-04-11T14:15:04+02:00" level=error msg="did not receive last pong ack from accesspoint, 245s passed" Apr 11 14:15:04 hudba go-librespot[3298412]: panic: runtime error: invalid memory address or nil pointer dereference Apr 11 14:15:04 hudba go-librespot[3298412]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x8a6d9b] Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 99 gp=0xc00034cfc0 m=4 mp=0xc000063808 [running]: Apr 11 14:15:04 hudba go-librespot[3298412]: panic({0xbbb580?, 0x1420450?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/panic.go:802 +0x168 fp=0xc00021ced8 sp=0xc00021ce28 pc=0x4889e8 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.panicmem(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/panic.go:262 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.sigpanic() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/signal_unix.go:925 +0x359 fp=0xc00021cf38 sp=0xc00021ced8 pc=0x48afb9 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0xc0004800f0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:380 +0x1fb fp=0xc00021cfc8 sp=0xc00021cf38 pc=0x8a6d9b Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).startReceiving.func1.gowrap2() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:277 +0x25 fp=0xc00021cfe0 sp=0xc00021cfc8 pc=0x8a62a5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00021cfe8 sp=0xc00021cfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).startReceiving.func1 in goroutine 83 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:277 +0xff Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 1 gp=0xc000002380 m=nil [select, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc000045c58?, 0x2?, 0x60?, 0x28?, 0xc000045bf4?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc0004e3a68 sp=0xc0004e3a48 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc0004e3c58, 0xc000045bf0, 0xc00011c068?, 0x0, 0x0?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc0004e3ba8 sp=0xc0004e3a68 pc=0x467bd7 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0xc0002860a0, 0xc0004e3d80) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/zeroconf/zeroconf.go:300 +0x2aa fp=0xc0004e3cf8 sp=0xc0004e3ba8 pc=0x9b2aca Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).withAppPlayer(0xc00031a400, {0xe22968, 0x14ad0c0}, 0xc000302ce0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:340 +0x5d0 fp=0xc0004e3e10 sp=0xc0004e3cf8 pc=0xa3fd70 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).withCredentials(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:209 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).SpotifyToken(0xc00031a400, {0xe22968, 0x14ad0c0}, {0xc000150e80?, 0xcfc256?}, {0xc0001203c0?, 0x2697?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:201 +0xc5 fp=0xc0004e3e68 sp=0xc0004e3e10 pc=0xa3f1e5 Apr 11 14:15:04 hudba go-librespot[3298412]: main.main() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:620 +0x745 fp=0xc0004e3f50 sp=0xc0004e3e68 pc=0xa42245 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.main() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:285 +0x29d fp=0xc0004e3fe0 sp=0xc0004e3f50 pc=0x45509d Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0004e3fe8 sp=0xc0004e3fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 2 gp=0xc000002e00 m=nil [force gc (idle), 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x4513e4e45ff2b?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005cfa8 sp=0xc00005cf88 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goparkunlock(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:466 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.forcegchelper() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:373 +0xb3 fp=0xc00005cfe0 sp=0xc00005cfa8 pc=0x4553d3 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005cfe8 sp=0xc00005cfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.init.7 in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:361 +0x1a Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 3 gp=0xc000003340 m=nil [GC sweep wait, 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005d780 sp=0xc00005d760 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goparkunlock(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:466 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.bgsweep(0xc00007e000) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgcsweep.go:323 +0xdf fp=0xc00005d7c8 sp=0xc00005d780 pc=0x43f29f Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcenable.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:212 +0x25 fp=0xc00005d7e0 sp=0xc00005d7c8 pc=0x4332a5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005d7e8 sp=0xc00005d7e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcenable in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:212 +0x66 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 4 gp=0xc000003500 m=nil [GC scavenge wait, 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x10000?, 0xbd42e?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005df78 sp=0xc00005df58 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goparkunlock(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:466 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.(*scavengerState).park(0x148bba0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc00005dfa8 sp=0xc00005df78 pc=0x43cd29 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.bgscavenge(0xc00007e000) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc00005dfc8 sp=0xc00005dfa8 pc=0x43d2d9 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcenable.gowrap2() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:213 +0x25 fp=0xc00005dfe0 sp=0xc00005dfc8 pc=0x433245 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005dfe8 sp=0xc00005dfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcenable in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:213 +0xa5 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 18 gp=0xc000102380 m=nil [GOMAXPROCS updater (idle), 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000058788 sp=0xc000058768 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goparkunlock(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:466 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.updateMaxProcsGoroutine() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:6720 +0xe7 fp=0xc0000587e0 sp=0xc000058788 pc=0x4632c7 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0000587e8 sp=0xc0000587e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.defaultGOMAXPROCSUpdateEnable in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:6708 +0x37 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 19 gp=0xc0001028c0 m=nil [finalizer wait, 30 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0xd57e00?, 0xa0?, 0x1?, 0x2000000020?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005c620 sp=0xc00005c600 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.runFinalizers() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mfinal.go:210 +0x107 fp=0xc00005c7e0 sp=0xc00005c620 pc=0x4321a7 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005c7e8 sp=0xc00005c7e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.createfing in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mfinal.go:172 +0x3d Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 20 gp=0xc0001036c0 m=nil [cleanup wait, 30 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x7f0c2566cc00?, 0xc000058f90?, 0xb5?, 0x7a?, 0x7f0c2566cc00?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000058f68 sp=0xc000058f48 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goparkunlock(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:466 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.(*cleanupQueue).dequeue(0x148bfe0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mcleanup.go:439 +0xc5 fp=0xc000058fa0 sp=0xc000058f68 pc=0x42f3c5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.runCleanups() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mcleanup.go:635 +0x45 fp=0xc000058fe0 sp=0xc000058fa0 pc=0x42fa85 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc000058fe8 sp=0xc000058fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.(*cleanupQueue).createGs in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mcleanup.go:589 +0xa5 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 36 gp=0xc00034c000 m=nil [IO wait, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00006ca58 sp=0xc00006ca38 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.netpollblock(0xc00006caa8?, 0x41f886?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:575 +0xf7 fp=0xc00006ca90 sp=0xc00006ca58 pc=0x44d977 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.runtime_pollWait(0x7f0c27025e00, 0x72) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:351 +0x85 fp=0xc00006cab0 sp=0xc00006ca90 pc=0x4880e5 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).wait(0xc000318280?, 0x90042984a?, 0x0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc00006cad8 sp=0xc00006cab0 pc=0x50b687 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).waitRead(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*FD).Accept(0xc000318280) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x28c fp=0xc00006cb80 sp=0xc00006cad8 pc=0x510aac Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*netFD).accept(0xc000318280) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/fd_unix.go:161 +0x29 fp=0xc00006cc38 sp=0xc00006cb80 pc=0x57d2a9 Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*TCPListener).accept(0xc000332140) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x1b fp=0xc00006cc88 sp=0xc00006cc38 pc=0x592a1b Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*TCPListener).Accept(0xc000332140) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0xc00006ccb8 sp=0xc00006cc88 pc=0x591bf0 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*onceCloseListener).Accept(0xc0003e38c0?) Apr 11 14:15:04 hudba go-librespot[3298412]: :1 +0x24 fp=0xc00006ccd0 sp=0xc00006ccb8 pc=0x73b104 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*Server).Serve(0xc0001a2900, {0xe218d0, 0xc000332140}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:3463 +0x30c fp=0xc00006ce00 sp=0xc00006ccd0 pc=0x71306c Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.Serve(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2971 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*ConcreteApiServer).serve(0xc000340120) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/api_server.go:666 +0x90c fp=0xc00006cfc8 sp=0xc00006ce00 pc=0xa3504c Apr 11 14:15:04 hudba go-librespot[3298412]: main.NewApiServer.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/api_server.go:332 +0x25 fp=0xc00006cfe0 sp=0xc00006cfc8 pc=0xa33d85 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00006cfe8 sp=0xc00006cfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by main.NewApiServer in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/api_server.go:332 +0x2ff Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 83 gp=0xc00034c1c0 m=nil [select, 6 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc0000abed0?, 0xa?, 0x0?, 0x0?, 0xc0000ab6c0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc0000ab318 sp=0xc0000ab2f8 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc0000abed0, 0xc0000ab6ac, 0x14ad0c0?, 0x0, 0x1d?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc0000ab458 sp=0xc0000ab318 pc=0x467bd7 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*AppPlayer).Run(0xc0001a0880, {0xe22968, 0x14ad0c0}, 0xc00030e7e0, 0xc00030e850) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/player.go:661 +0x427 fp=0xc0000abfa8 sp=0xc0000ab458 pc=0xa47f47 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).withAppPlayer.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:274 +0x30 fp=0xc0000abfe0 sp=0xc0000abfa8 pc=0xa40990 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0000abfe8 sp=0xc0000abfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by main.(*App).withAppPlayer in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:274 +0x405 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 40 gp=0xc00034c380 m=nil [chan receive, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0xb9cf60?, 0x0?, 0x0?, 0xc0003517a8?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000351718 sp=0xc0003516f8 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv(0xc00030e000, 0x0, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:667 +0x473 fp=0xc000351790 sp=0xc000351718 pc=0x422773 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv1(0xc0001780f0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:509 +0x12 fp=0xc0003517b8 sp=0xc000351790 pc=0x4222d2 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/godbus/dbus/v5.newConn.func1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:303 +0x2c fp=0xc0003517e0 sp=0xc0003517b8 pc=0x85b32c Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0003517e8 sp=0xc0003517e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/godbus/dbus/v5.newConn in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:302 +0x4da Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 22 gp=0xc00034c540 m=nil [GC worker (idle), 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x44f7e99b82740?, 0x0?, 0xb0?, 0xc5?, 0xc00033c620?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000352738 sp=0xc000352718 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkWorker(0xc000111810) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1463 +0xeb fp=0xc0003527c8 sp=0xc000352738 pc=0x43598b Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkStartWorkers.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x25 fp=0xc0003527e0 sp=0xc0003527c8 pc=0x435865 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0003527e8 sp=0xc0003527e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcBgMarkStartWorkers in goroutine 7 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x105 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 29 gp=0xc000003a40 m=nil [IO wait, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc000040700?, 0xc0001e73a8?, 0xa8?, 0x73?, 0xb?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc0001e7338 sp=0xc0001e7318 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.netpollblock(0x4ac6d8?, 0x41f886?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:575 +0xf7 fp=0xc0001e7370 sp=0xc0001e7338 pc=0x44d977 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.runtime_pollWait(0x7f0c27025a00, 0x72) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:351 +0x85 fp=0xc0001e7390 sp=0xc0001e7370 pc=0x4880e5 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).wait(0xc000318080?, 0xc0000c8000?, 0x0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc0001e73b8 sp=0xc0001e7390 pc=0x50b687 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).waitRead(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*FD).Read(0xc000318080, {0xc0000c8000, 0x1000, 0x1000}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_unix.go:165 +0x279 fp=0xc0001e7450 sp=0xc0001e73b8 pc=0x50c979 Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*netFD).Read(0xc000318080, {0xc0000c8000?, 0x7f0c6f45a5c0?, 0x10?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/fd_posix.go:68 +0x25 fp=0xc0001e7498 sp=0xc0001e7450 pc=0x57b405 Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*conn).Read(0xc0003080c0, {0xc0000c8000?, 0x10?, 0xc0001e7520?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/net.go:196 +0x45 fp=0xc0001e74e0 sp=0xc0001e7498 pc=0x589925 Apr 11 14:15:04 hudba go-librespot[3298412]: io.(*multiReader).Read(0xc0004b88e8, {0xc0000c8000, 0x1000, 0x1000}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/io/multi.go:26 +0x93 fp=0xc0001e7528 sp=0xc0001e74e0 pc=0x4ca073 Apr 11 14:15:04 hudba go-librespot[3298412]: bufio.(*Reader).fill(0xc00008ad80) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/bufio/bufio.go:113 +0x103 fp=0xc0001e7560 sp=0xc0001e7528 pc=0x68e823 Apr 11 14:15:04 hudba go-librespot[3298412]: bufio.(*Reader).ReadByte(0xc00008ad80) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/bufio/bufio.go:273 +0x27 fp=0xc0001e7580 sp=0xc0001e7560 pc=0x68ef47 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.readFrameHeader(0xc00008ad80, {0xc000394240, 0x8, 0x8}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/frame.go:55 +0x85 fp=0xc0001e7610 sp=0xc0001e7580 pc=0x745ae5 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.(*Conn).readFrameHeader(0xc0003941e0, {0xe22930, 0x14ad0c0}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:266 +0xe5 fp=0xc0001e76e8 sp=0xc0001e7610 pc=0x747925 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.(*Conn).readLoop(0xc0003941e0, {0xe22930, 0x14ad0c0}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:185 +0x65 fp=0xc0001e7848 sp=0xc0001e76e8 pc=0x746f45 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.(*Conn).reader(0xc0003941e0, {0xe22930, 0x14ad0c0}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:381 +0x10f fp=0xc0001e7938 sp=0xc0001e7848 pc=0x7486af Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.(*Conn).Reader(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:36 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/coder/websocket.(*Conn).Read(0xc000340198?, {0xe22930?, 0x14ad0c0?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:42 +0x1e fp=0xc0001e7968 sp=0xc0001e7938 pc=0x7466fe Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*ConcreteApiServer).serve.func17({0xe21a50, 0xc0001ee780}, 0xc000095620?) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/api_server.go:636 +0x39f fp=0xc0001e7a68 sp=0xc0001e7968 pc=0xa357ff Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.HandlerFunc.ServeHTTP(0xc0001566c0?, {0xe21a50?, 0xc0001ee780?}, 0x2000000000000?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2322 +0x29 fp=0xc0001e7a90 sp=0xc0001e7a68 pc=0x70f769 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*ServeMux).ServeHTTP(0xc000278d00?, {0xe21a50, 0xc0001ee780}, 0xc00019c3c0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2861 +0x1c7 fp=0xc0001e7ae0 sp=0xc0001e7a90 pc=0x711647 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0xe21a50, 0xc0001ee780}, 0xc00019c3c0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x164 fp=0xc0001e7b38 sp=0xc0001e7ae0 pc=0xa35284 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.HandlerFunc.ServeHTTP(0x485cb9?, {0xe21a50?, 0xc0001ee780?}, 0xc000072b68?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2322 +0x29 fp=0xc0001e7b60 sp=0xc0001e7b38 pc=0x70f769 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.serverHandler.ServeHTTP({0xc000332700?}, {0xe21a50?, 0xc0001ee780?}, 0x1?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:3340 +0x8e fp=0xc0001e7b90 sp=0xc0001e7b60 pc=0x72ebee Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*conn).serve(0xc0003407e0, {0xe229a0, 0xc00026be90}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2109 +0x665 fp=0xc0001e7fb8 sp=0xc0001e7b90 pc=0x70d865 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*Server).Serve.gowrap3() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:3493 +0x28 fp=0xc0001e7fe0 sp=0xc0001e7fb8 pc=0x713468 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0001e7fe8 sp=0xc0001e7fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by net/http.(*Server).Serve in goroutine 36 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:3493 +0x485 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 23 gp=0xc0002d5180 m=nil [GC worker (idle), 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x44f7e99b80948?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005e738 sp=0xc00005e718 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkWorker(0xc000111810) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1463 +0xeb fp=0xc00005e7c8 sp=0xc00005e738 pc=0x43598b Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkStartWorkers.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x25 fp=0xc00005e7e0 sp=0xc00005e7c8 pc=0x435865 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005e7e8 sp=0xc00005e7e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcBgMarkStartWorkers in goroutine 7 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x105 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 24 gp=0xc0002d5340 m=nil [GC worker (idle), 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x14ae960?, 0x1?, 0xa8?, 0x5a?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00005b738 sp=0xc00005b718 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkWorker(0xc000111810) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1463 +0xeb fp=0xc00005b7c8 sp=0xc00005b738 pc=0x43598b Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkStartWorkers.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x25 fp=0xc00005b7e0 sp=0xc00005b7c8 pc=0x435865 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00005b7e8 sp=0xc00005b7e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcBgMarkStartWorkers in goroutine 7 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x105 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 25 gp=0xc0002d5500 m=nil [GC worker (idle), 4 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x45121a74723ae?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000354738 sp=0xc000354718 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkWorker(0xc000111810) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1463 +0xeb fp=0xc0003547c8 sp=0xc000354738 pc=0x43598b Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gcBgMarkStartWorkers.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x25 fp=0xc0003547e0 sp=0xc0003547c8 pc=0x435865 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0003547e8 sp=0xc0003547e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by runtime.gcBgMarkStartWorkers in goroutine 7 Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/mgc.go:1373 +0x105 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 9 gp=0xc0002d48c0 m=nil [IO wait, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000361a80 sp=0xc000361a60 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.netpollblock(0x0?, 0x41f886?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:575 +0xf7 fp=0xc000361ab8 sp=0xc000361a80 pc=0x44d977 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.runtime_pollWait(0x7f0c27025600, 0x72) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:351 +0x85 fp=0xc000361ad8 sp=0xc000361ab8 pc=0x4880e5 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).wait(0xc0001a0380?, 0xc000014080?, 0x0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000361b00 sp=0xc000361ad8 pc=0x50b687 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).waitRead(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*FD).ReadMsg(0xc0001a0380, {0xc000014080, 0x10, 0x10}, {0xc00031c028, 0x1000, 0x1000}, 0x40000000) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_unix.go:295 +0x385 fp=0xc000361be8 sp=0xc000361b00 pc=0x50db45 Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*netFD).readMsg(0xc0001a0380, {0xc000014080?, 0xc000302820?, 0xc000361cb8?}, {0xc00031c028?, 0x20?, 0xba1820?}, 0xc?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/fd_posix.go:91 +0x31 fp=0xc000361c70 sp=0xc000361be8 pc=0x57b811 Apr 11 14:15:04 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Apr 11 14:15:04 hudba volumio[3298200]: info: Connection to go-librespot Websocket closed Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*UnixConn).readMsg(0xc000060000, {0xc000014080?, 0x2?, 0xc000361d48?}, {0xc00031c028?, 0xc000361e00?, 0x863e7c?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/unixsock_posix.go:115 +0x3d fp=0xc000361d00 sp=0xc000361c70 pc=0x598cbd Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*UnixConn).ReadMsgUnix(0xc000060000, {0xc000014080?, 0xc00003e4e0?, 0xc000361dc0?}, {0xc00031c028?, 0x0?, 0xc000302820?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/unixsock.go:143 +0x36 fp=0xc000361d78 sp=0xc000361d00 pc=0x5972b6 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/godbus/dbus/v5.(*oobReader).Read(0xc00031c008, {0xc000014080?, 0x2d?, 0x42a214?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:41 +0x3c fp=0xc000361df0 sp=0xc000361d78 pc=0x87313c Apr 11 14:15:04 hudba go-librespot[3298412]: io.ReadAtLeast({0xe1ada0, 0xc00031c008}, {0xc000014080, 0x10, 0x10}, 0x10) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/io/io.go:335 +0x8e fp=0xc000361e38 sp=0xc000361df0 pc=0x4c91ae Apr 11 14:15:04 hudba go-librespot[3298412]: io.ReadFull(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/io/io.go:354 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/godbus/dbus/v5.(*unixTransport).ReadMessage(0xc000012108) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:124 +0x225 fp=0xc000361f58 sp=0xc000361e38 pc=0x873825 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/godbus/dbus/v5.(*Conn).inWorker(0xc0002d0000) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:390 +0x37 fp=0xc000361fc8 sp=0xc000361f58 pc=0x85b857 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/godbus/dbus/v5.(*Conn).Auth.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x25 fp=0xc000361fe0 sp=0xc000361fc8 pc=0x8591c5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc000361fe8 sp=0xc000361fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/godbus/dbus/v5.(*Conn).Auth in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x7ec Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 101 gp=0xc000003dc0 m=nil [select]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc000072f98?, 0x2?, 0x20?, 0xe0?, 0xc000072f44?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000072dc8 sp=0xc000072da8 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc000072f98, 0xc000072f40, 0x0?, 0x0, 0xc000015f31?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc000072f08 sp=0xc000072dc8 pc=0x467bd7 Apr 11 14:15:04 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/dealer.(*Dealer).pingTicker(0xc0000bc0e0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:138 +0x8f fp=0xc000072fc8 sp=0xc000072f08 pc=0x92efaf Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/dealer.(*Dealer).startReceiving.func1.gowrap2() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:129 +0x25 fp=0xc000072fe0 sp=0xc000072fc8 pc=0x92ee85 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc000072fe8 sp=0xc000072fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).startReceiving.func1 in goroutine 83 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:129 +0xf6 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 100 gp=0xc000103880 m=nil [select, 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc0001e5de0?, 0x2?, 0x45?, 0x93?, 0xc0001e5d8c?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc0003ccc10 sp=0xc0003ccbf0 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc0003ccde0, 0xc0001e5d88, 0xb63ae0?, 0x0, 0x429897?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc0003ccd50 sp=0xc0003ccc10 pc=0x467bd7 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0xc0003cce78?, {0xe204d8, 0xc0001328a0}, 0x0, {0x0, 0x0?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:112 +0x245 fp=0xc0003cce40 sp=0xc0003ccd50 pc=0x89aa25 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x0?, {0xe204d8?, 0xc0001328a0?}, 0x0?, {0x0?, 0x0?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x56 fp=0xc0003cce98 sp=0xc0003cce40 pc=0x89a496 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.RetryNotify(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.Retry(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/dealer.(*Dealer).recvLoop(0xc0000bc0e0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:237 +0x550 fp=0xc0003ccfc8 sp=0xc0003cce98 pc=0x92f850 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/dealer.(*Dealer).startReceiving.func1.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:125 +0x25 fp=0xc0003ccfe0 sp=0xc0003ccfc8 pc=0x92eee5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0003ccfe8 sp=0xc0003ccfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).startReceiving.func1 in goroutine 83 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/dealer/dealer.go:125 +0x78 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 82 gp=0xc0004b6000 m=nil [select, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc00021ff20?, 0x3?, 0xa?, 0x0?, 0xc00021feda?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00021fd60 sp=0xc00021fd40 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc00021ff20, 0xc00021fed4, 0xc0002046b0?, 0x0, 0x1f?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc00021fea0 sp=0xc00021fd60 pc=0x467bd7 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0xc00009ab80) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/player/player.go:215 +0x205 fp=0xc00021ffc8 sp=0xc00021fea0 pc=0x912865 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/player/player.go:197 +0x25 fp=0xc00021ffe0 sp=0xc00021ffc8 pc=0x912425 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00021ffe8 sp=0xc00021ffe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/player/player.go:197 +0x1e5 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 84 gp=0xc0004b6540 m=nil [chan receive, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc000310540?, 0xc0003ea2a0?, 0x20?, 0xc4?, 0xc000352ee8?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000352e98 sp=0xc000352e78 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv(0xc00033c070, 0xc000352f98, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:667 +0x473 fp=0xc000352f10 sp=0xc000352e98 pc=0x422773 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv2(0x644b9c?, 0xc000352fa0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:514 +0x12 fp=0xc000352f38 sp=0xc000352f10 pc=0x4222f2 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).withAppPlayer.func1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:284 +0x72 fp=0xc000352fe0 sp=0xc000352f38 pc=0xa408d2 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc000352fe8 sp=0xc000352fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by main.(*App).withAppPlayer in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:281 +0x49f Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 85 gp=0xc0004b6700 m=nil [chan receive, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc00034f698 sp=0xc00034f678 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv(0xc00033c000, 0xc00034f7b8, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:667 +0x473 fp=0xc00034f710 sp=0xc00034f698 pc=0x422773 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.chanrecv2(0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/chan.go:514 +0x12 fp=0xc00034f738 sp=0xc00034f710 pc=0x4222f2 Apr 11 14:15:04 hudba go-librespot[3298412]: main.(*App).withAppPlayer.func2() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:300 +0x87 fp=0xc00034f7e0 sp=0xc00034f738 pc=0xa40507 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc00034f7e8 sp=0xc00034f7e0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by main.(*App).withAppPlayer in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/cmd/daemon/main.go:297 +0x55f Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 86 gp=0xc0004b68c0 m=nil [IO wait, 32 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc000218be0 sp=0xc000218bc0 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.netpollblock(0x433636?, 0x41f886?, 0x0?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:575 +0xf7 fp=0xc000218c18 sp=0xc000218be0 pc=0x44d977 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.runtime_pollWait(0x7f0c27025800, 0x72) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/netpoll.go:351 +0x85 fp=0xc000218c38 sp=0xc000218c18 pc=0x4880e5 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).wait(0xc0001a0300?, 0x7f0c6f45a5c0?, 0x0) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000218c60 sp=0xc000218c38 pc=0x50b687 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*pollDesc).waitRead(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Apr 11 14:15:04 hudba go-librespot[3298412]: internal/poll.(*FD).Accept(0xc0001a0300) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x28c fp=0xc000218d08 sp=0xc000218c60 pc=0x510aac Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*netFD).accept(0xc0001a0300) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/fd_unix.go:161 +0x29 fp=0xc000218dc0 sp=0xc000218d08 pc=0x57d2a9 Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*TCPListener).accept(0xc0002f4180) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x1b fp=0xc000218e10 sp=0xc000218dc0 pc=0x592a1b Apr 11 14:15:04 hudba go-librespot[3298412]: net.(*TCPListener).Accept(0xc0002f4180) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0xc000218e40 sp=0xc000218e10 pc=0x591bf0 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*onceCloseListener).Accept(0xe22930?) Apr 11 14:15:04 hudba go-librespot[3298412]: :1 +0x24 fp=0xc000218e58 sp=0xc000218e40 pc=0x73b104 Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.(*Server).Serve(0xc0001a2c00, {0xe218d0, 0xc0002f4180}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:3463 +0x30c fp=0xc000218f88 sp=0xc000218e58 pc=0x71306c Apr 11 14:15:04 hudba go-librespot[3298412]: net/http.Serve(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/net/http/server.go:2971 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/zeroconf/zeroconf.go:297 +0x85 fp=0xc000218fe0 sp=0xc000218f88 pc=0x9b2be5 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc000218fe8 sp=0xc000218fe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/zeroconf/zeroconf.go:297 +0x169 Apr 11 14:15:04 hudba go-librespot[3298412]: goroutine 98 gp=0xc00034d180 m=nil [select, 2 minutes]: Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.gopark(0xc00035bd60?, 0x2?, 0x45?, 0x93?, 0xc00035bd0c?) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/proc.go:460 +0xce fp=0xc0003cbb90 sp=0xc0003cbb70 pc=0x488f0e Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.selectgo(0xc0003cbd60, 0xc00035bd08, 0xb63ae0?, 0x0, 0x429897?, 0x1) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/select.go:351 +0x8b7 fp=0xc0003cbcd0 sp=0xc0003cbb90 pc=0x467bd7 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0xc0003cbdf8?, {0xe204d8, 0xc0003ea120}, 0x0, {0x0, 0x0?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:112 +0x245 fp=0xc0003cbdc0 sp=0xc0003cbcd0 pc=0x89aa25 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x0?, {0xe204d8?, 0xc0003ea120?}, 0x0?, {0x0?, 0x0?}) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x56 fp=0xc0003cbe18 sp=0xc0003cbdc0 pc=0x89a496 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.RetryNotify(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/cenkalti/backoff/v4.Retry(...) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0xc0004800f0) Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:335 +0x451 fp=0xc0003cbfc8 sp=0xc0003cbe18 pc=0x8a6791 Apr 11 14:15:04 hudba go-librespot[3298412]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).startReceiving.func1.gowrap1() Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:273 +0x25 fp=0xc0003cbfe0 sp=0xc0003cbfc8 pc=0x8a6305 Apr 11 14:15:04 hudba go-librespot[3298412]: runtime.goexit({}) Apr 11 14:15:04 hudba go-librespot[3298412]: /usr/local/go/src/runtime/asm_amd64.s:1693 +0x1 fp=0xc0003cbfe8 sp=0xc0003cbfe0 pc=0x490a41 Apr 11 14:15:04 hudba go-librespot[3298412]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).startReceiving.func1 in goroutine 83 Apr 11 14:15:04 hudba go-librespot[3298412]: /src/ap/ap.go:273 +0x78 Apr 11 14:15:04 hudba go-librespot[3298410]: Aborted Apr 11 14:15:06 hudba nmbd[1164]: [2026/04/11 14:15:06.000805, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Apr 11 14:15:06 hudba nmbd[1164]: Packet send failed to 192.168.0.255(138) ERRNO=Network is unreachable Apr 11 14:15:06 hudba nmbd[1164]: [2026/04/11 14:15:06.007330, 0] ../../source3/nmbd/nmbd.c:359(reload_interfaces) Apr 11 14:15:06 hudba nmbd[1164]: reload_interfaces: No subnets to listen to. Waiting.. Apr 11 14:15:07 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:07 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:07 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 11 14:15:07 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:07 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:07 hudba go-librespot[3304093]: go-librespot daemon starting... Apr 11 14:15:07 hudba go-librespot[3304094]: time="2026-04-11T14:15:07+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:07 hudba go-librespot[3304094]: time="2026-04-11T14:15:07+02:00" level=debug msg="app state loaded" Apr 11 14:15:07 hudba go-librespot[3304094]: time="2026-04-11T14:15:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:07 hudba go-librespot[3304094]: time="2026-04-11T14:15:07+02: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" Apr 11 14:15:07 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:07 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:09 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:09 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:09 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:09 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:09 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:09.618+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:09 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:09.620+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:10 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:10.532+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:10 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:10 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:11 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 11 14:15:11 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:11 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:11 hudba go-librespot[3304106]: go-librespot daemon starting... Apr 11 14:15:11 hudba go-librespot[3304107]: time="2026-04-11T14:15:11+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:11 hudba go-librespot[3304107]: time="2026-04-11T14:15:11+02:00" level=debug msg="app state loaded" Apr 11 14:15:11 hudba go-librespot[3304107]: time="2026-04-11T14:15:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:11 hudba go-librespot[3304107]: time="2026-04-11T14:15:11+02: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" Apr 11 14:15:11 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:11 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:13 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:13 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:14 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 11 14:15:14 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:14 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:14 hudba go-librespot[3304118]: go-librespot daemon starting... Apr 11 14:15:14 hudba go-librespot[3304119]: time="2026-04-11T14:15:14+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:14 hudba go-librespot[3304119]: time="2026-04-11T14:15:14+02:00" level=debug msg="app state loaded" Apr 11 14:15:14 hudba go-librespot[3304119]: time="2026-04-11T14:15:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:14 hudba go-librespot[3304119]: time="2026-04-11T14:15:14+02: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" Apr 11 14:15:14 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:14 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:15 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:15 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:15 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:15 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:15 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:15.562+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:15 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:15.564+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:16 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:16.390+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:16 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:16 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:17 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 11 14:15:17 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:17 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:17 hudba go-librespot[3304146]: go-librespot daemon starting... Apr 11 14:15:17 hudba go-librespot[3304147]: time="2026-04-11T14:15:17+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:17 hudba go-librespot[3304147]: time="2026-04-11T14:15:17+02:00" level=debug msg="app state loaded" Apr 11 14:15:17 hudba go-librespot[3304147]: time="2026-04-11T14:15:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:17 hudba go-librespot[3304147]: time="2026-04-11T14:15:17+02: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" Apr 11 14:15:17 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:17 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:19 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:19 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:20 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 11 14:15:20 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:20 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:20 hudba go-librespot[3304159]: go-librespot daemon starting... Apr 11 14:15:20 hudba go-librespot[3304160]: time="2026-04-11T14:15:20+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:20 hudba go-librespot[3304160]: time="2026-04-11T14:15:20+02:00" level=debug msg="app state loaded" Apr 11 14:15:20 hudba go-librespot[3304160]: time="2026-04-11T14:15:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:20 hudba go-librespot[3304160]: time="2026-04-11T14:15:20+02: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" Apr 11 14:15:20 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:20 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:21 hudba wpa_supplicant[1243]: wlan0: SME: Trying to authenticate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Apr 11 14:15:21 hudba kernel: wlan0: authenticate with 30:68:93:02:fa:75 (local address=c0:18:85:79:67:ab) Apr 11 14:15:21 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 1/3) Apr 11 14:15:21 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 2/3) Apr 11 14:15:21 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 3/3) Apr 11 14:15:21 hudba kernel: wlan0: authentication with 30:68:93:02:fa:75 timed out Apr 11 14:15:21 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:21 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:21 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:21 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:21 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:21.548+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:21 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:21.551+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:22 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:22.375+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:22 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:22 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:23 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:23 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:23 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:23 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:23 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:23.803+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:23 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:23.805+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:24 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 11 14:15:24 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:24 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:24 hudba go-librespot[3304171]: go-librespot daemon starting... Apr 11 14:15:24 hudba go-librespot[3304172]: time="2026-04-11T14:15:24+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:24 hudba go-librespot[3304172]: time="2026-04-11T14:15:24+02:00" level=debug msg="app state loaded" Apr 11 14:15:24 hudba go-librespot[3304172]: time="2026-04-11T14:15:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:24 hudba go-librespot[3304172]: time="2026-04-11T14:15:24+02: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" Apr 11 14:15:24 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:24 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:24 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:24.786+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:25 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:25 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:27 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Apr 11 14:15:27 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:27 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:27 hudba go-librespot[3304198]: go-librespot daemon starting... Apr 11 14:15:27 hudba go-librespot[3304199]: time="2026-04-11T14:15:27+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:27 hudba go-librespot[3304199]: time="2026-04-11T14:15:27+02:00" level=debug msg="app state loaded" Apr 11 14:15:27 hudba go-librespot[3304199]: time="2026-04-11T14:15:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:27 hudba go-librespot[3304199]: time="2026-04-11T14:15:27+02: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" Apr 11 14:15:27 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:27 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:28 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:28 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: SME: Trying to authenticate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Apr 11 14:15:29 hudba kernel: wlan0: authenticate with 30:68:93:02:fa:75 (local address=c0:18:85:79:67:ab) Apr 11 14:15:29 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 1/3) Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: Trying to associate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Apr 11 14:15:29 hudba kernel: wlan0: authenticated Apr 11 14:15:29 hudba kernel: wlan0: associate with 30:68:93:02:fa:75 (try 1/3) Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: Associated with 30:68:93:02:fa:75 Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 11 14:15:29 hudba kernel: wlan0: RX AssocResp from 30:68:93:02:fa:75 (capab=0x411 status=0 aid=2) Apr 11 14:15:29 hudba kernel: wlan0: associated Apr 11 14:15:29 hudba wpa_supplicant[1243]: RRM: Ignoring radio measurement request: Not associated Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: WPA: Key negotiation completed with 30:68:93:02:fa:75 [PTK=CCMP GTK=CCMP] Apr 11 14:15:29 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-CONNECTED - Connection to 30:68:93:02:fa:75 completed [id=0 id_str=] Apr 11 14:15:29 hudba dhcpcd[806]: wlan0: carrier acquired Apr 11 14:15:29 hudba dhcpcd[806]: wlan0: IAID 85:79:67:ab Apr 11 14:15:29 hudba dhcpcd[806]: wlan0: soliciting an IPv6 router Apr 11 14:15:30 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:30 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:30 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:30 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:30 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:30.030+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:30 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:30.032+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:30 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Apr 11 14:15:30 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:30 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:30 hudba go-librespot[3304211]: go-librespot daemon starting... Apr 11 14:15:30 hudba go-librespot[3304212]: time="2026-04-11T14:15:30+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:30 hudba go-librespot[3304212]: time="2026-04-11T14:15:30+02:00" level=debug msg="app state loaded" Apr 11 14:15:30 hudba go-librespot[3304212]: time="2026-04-11T14:15:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:30 hudba go-librespot[3304212]: time="2026-04-11T14:15:30+02: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" Apr 11 14:15:30 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:30 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:31 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:31.014+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:31 hudba dhcpcd[806]: wlan0: rebinding lease of 192.168.0.105 Apr 11 14:15:31 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:31 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:32 hudba dhcpcd[806]: wlan0: probing address 192.168.0.105/24 Apr 11 14:15:33 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Apr 11 14:15:33 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:33 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:33 hudba go-librespot[3304226]: go-librespot daemon starting... Apr 11 14:15:33 hudba go-librespot[3304227]: time="2026-04-11T14:15:33+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:33 hudba go-librespot[3304227]: time="2026-04-11T14:15:33+02:00" level=debug msg="app state loaded" Apr 11 14:15:33 hudba go-librespot[3304227]: time="2026-04-11T14:15:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:33 hudba go-librespot[3304227]: time="2026-04-11T14:15:33+02: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" Apr 11 14:15:33 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:33 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:34 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:34 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:37 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Apr 11 14:15:37 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:37 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:37 hudba go-librespot[3304253]: go-librespot daemon starting... Apr 11 14:15:37 hudba go-librespot[3304254]: time="2026-04-11T14:15:37+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:37 hudba go-librespot[3304254]: time="2026-04-11T14:15:37+02:00" level=debug msg="app state loaded" Apr 11 14:15:37 hudba go-librespot[3304254]: time="2026-04-11T14:15:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:37 hudba go-librespot[3304254]: time="2026-04-11T14:15:37+02: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" Apr 11 14:15:37 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:37 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:37 hudba dhcpcd[806]: wlan0: leased 192.168.0.105 for 7200 seconds Apr 11 14:15:37 hudba avahi-daemon[1510]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.105. Apr 11 14:15:37 hudba avahi-daemon[1510]: New relevant interface wlan0.IPv4 for mDNS. Apr 11 14:15:37 hudba avahi-daemon[1510]: Registering new address record for 192.168.0.105 on wlan0.IPv4. Apr 11 14:15:37 hudba dhcpcd[806]: wlan0: adding route to 192.168.0.0/24 Apr 11 14:15:37 hudba dhcpcd[806]: wlan0: adding default route via 192.168.0.1 Apr 11 14:15:37 hudba systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:15:37 hudba systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 11 14:15:37 hudba systemd[1]: welcome.service: Deactivated successfully. Apr 11 14:15:37 hudba systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 11 14:15:37 hudba systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 11 14:15:37 hudba systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 11 14:15:37 hudba welcome[3304277]: Resolved ip:[1] 192.168.0.105 Apr 11 14:15:37 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:37 hudba systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 11 14:15:37 hudba volumio[3298200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 14:15:37 hudba systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:15:38 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:38 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:38 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:38 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:38 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:38.189+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:38 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:38.191+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:39 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:39.044+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:39 hudba ntpd[1119]: IO: Listen normally on 1506 wlan0 192.168.0.105:123 Apr 11 14:15:39 hudba ntpd[1119]: IO: new interface(s) found: waking up resolver Apr 11 14:15:40 hudba volumio[3298200]: info: Discovery: adding ae412730-5e6a-429a-9912-105bacee40ef Apr 11 14:15:40 hudba volumio[3298200]: info: Discovery: Found device Hudba Apr 11 14:15:40 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:40 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:40 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Apr 11 14:15:40 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:40 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:40 hudba go-librespot[3304292]: go-librespot daemon starting... Apr 11 14:15:40 hudba go-librespot[3304293]: time="2026-04-11T14:15:40+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:40 hudba go-librespot[3304293]: time="2026-04-11T14:15:40+02:00" level=debug msg="app state loaded" Apr 11 14:15:40 hudba go-librespot[3304293]: time="2026-04-11T14:15:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:40 hudba volumio[3298200]: info: Initializing connection to go-librespot Websocket Apr 11 14:15:40 hudba go-librespot[3304293]: time="2026-04-11T14:15:40+02:00" level=debug msg="new websocket client" Apr 11 14:15:40 hudba volumio[3298200]: info: Connection to go-librespot Websocket established Apr 11 14:15:43 hudba volumio[3298200]: info: Getting Spotify volume Apr 11 14:15:43 hudba volumio[3298200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 11 14:15:43 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:43 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:43 hudba volumio[3298200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 11 14:15:45 hudba volumio[3298200]: info: Volumio Network Manager: Network status updated: 2 Apr 11 14:15:49 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-BEACON-LOSS Apr 11 14:15:49 hudba dhcpcd[806]: wlan0: carrier lost Apr 11 14:15:49 hudba avahi-daemon[1510]: Withdrawing address record for 192.168.0.105 on wlan0. Apr 11 14:15:49 hudba avahi-daemon[1510]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.105. Apr 11 14:15:49 hudba systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:15:49 hudba systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 11 14:15:49 hudba systemd[1]: welcome.service: Deactivated successfully. Apr 11 14:15:49 hudba systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 11 14:15:49 hudba systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 11 14:15:49 hudba systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 11 14:15:49 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-DISCONNECTED bssid=30:68:93:02:fa:75 reason=4 locally_generated=1 Apr 11 14:15:49 hudba avahi-daemon[1510]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 11 14:15:49 hudba dhcpcd[806]: wlan0: deleting route to 192.168.0.0/24 Apr 11 14:15:49 hudba dhcpcd[806]: wlan0: deleting default route via 192.168.0.1 Apr 11 14:15:49 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 11 14:15:49 hudba welcome[3304342]: Resolved ip:[0] Apr 11 14:15:49 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=SK Apr 11 14:15:49 hudba volumio[3298200]: info: Discovery: A device disappeared from network Apr 11 14:15:49 hudba systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 11 14:15:49 hudba systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:15:50 hudba volumio[3298200]: info: Received Get System Info Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:50 hudba volumio[3298200]: info: Discovery: Getting this device information Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:50 hudba volumio[3298200]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:50 hudba volumio[3298200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:50 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:50.391+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:50 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:50.393+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:50 hudba go-librespot[3304293]: time="2026-04-11T14:15:50+02: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\": net/http: TLS handshake timeout" Apr 11 14:15:50 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:50 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:50 hudba volumio[3298200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 14:15:50 hudba volumio[3298200]: Error: socket hang up Apr 11 14:15:50 hudba volumio[3298200]: at connResetException (node:internal/errors:720:14) Apr 11 14:15:50 hudba volumio[3298200]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 11 14:15:50 hudba volumio[3298200]: at Socket.emit (node:events:526:35) Apr 11 14:15:50 hudba volumio[3298200]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 11 14:15:50 hudba volumio[3298200]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 11 14:15:50 hudba volumio[3298200]: code: 'ECONNRESET', Apr 11 14:15:50 hudba volumio[3298200]: response: undefined Apr 11 14:15:50 hudba volumio[3298200]: } Apr 11 14:15:50 hudba volumio[3298200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 14:15:50 hudba wpa_supplicant[1243]: wlan0: SME: Trying to authenticate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Apr 11 14:15:50 hudba kernel: wlan0: authenticate with 30:68:93:02:fa:75 (local address=c0:18:85:79:67:ab) Apr 11 14:15:50 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 1/3) Apr 11 14:15:51 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 2/3) Apr 11 14:15:51 hudba wpa_supplicant[1243]: wlan0: Trying to associate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Apr 11 14:15:51 hudba kernel: wlan0: authenticated Apr 11 14:15:51 hudba kernel: wlan0: associate with 30:68:93:02:fa:75 (try 1/3) Apr 11 14:15:51 hudba kernel: wlan0: RX AssocResp from 30:68:93:02:fa:75 (capab=0x411 status=0 aid=2) Apr 11 14:15:51 hudba kernel: wlan0: associated Apr 11 14:15:51 hudba wpa_supplicant[1243]: wlan0: Associated with 30:68:93:02:fa:75 Apr 11 14:15:51 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 11 14:15:51 hudba wpa_supplicant[1243]: RRM: Ignoring radio measurement request: Not associated Apr 11 14:15:51 hudba sudo[3304373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 14:14' Apr 11 14:15:51 hudba sudo[3304373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:51 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:51.285+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:15:51 hudba sudo[3304373]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:51 hudba volumio-remote-updater[793]: [2026-04-11 14:15:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 11 14:15:51 hudba volumio-remote-updater[793]: [2026-04-11 14:15:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 11 14:15:51 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:51.473+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Apr 11 14:15:51 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:51.477+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 11 14:15:51 hudba systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:51 hudba systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 11 14:15:51 hudba systemd[1]: volumio.service: Consumed 40.181s CPU time. Apr 11 14:15:51 hudba systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 14:15:51 hudba systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 14:15:51 hudba systemd[1]: volumio.service: Scheduled restart job, restart counter is at 92. Apr 11 14:15:51 hudba systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 14:15:51 hudba systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 11 14:15:51 hudba systemd[1]: volumio.service: Consumed 40.181s CPU time. Apr 11 14:15:51 hudba systemd[1]: Started volumio.service - Volumio Backend Module. Apr 11 14:15:51 hudba systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 14:15:52 hudba wpa_supplicant[1243]: wlan0: WPA: Key negotiation completed with 30:68:93:02:fa:75 [PTK=CCMP GTK=CCMP] Apr 11 14:15:52 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-CONNECTED - Connection to 30:68:93:02:fa:75 completed [id=0 id_str=] Apr 11 14:15:52 hudba dhcpcd[806]: wlan0: carrier acquired Apr 11 14:15:52 hudba dhcpcd[806]: wlan0: IAID 85:79:67:ab Apr 11 14:15:52 hudba dhcpcd[806]: wlan0: soliciting an IPv6 router Apr 11 14:15:52 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:52.479+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 11 14:15:52 hudba dhcpcd[806]: wlan0: rebinding lease of 192.168.0.105 Apr 11 14:15:53 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:15:53 hudba volumio[3304410]: info: ----- Volumio3 ---- Apr 11 14:15:53 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:15:53 hudba volumio[3304410]: info: ----- System startup ---- Apr 11 14:15:53 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:15:53 hudba ntpd[1119]: IO: Deleting interface #1506 wlan0, 192.168.0.105#123, interface stats: received=0, sent=0, dropped=0, active_time=14 secs Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 185.112.249.67 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 212.55.254.189 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 193.87.160.18 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 95.131.202.21 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 84.245.104.80 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 185.242.56.5 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba ntpd[1119]: PROTO: 213.81.129.99 unlink local addr 192.168.0.105 -> Apr 11 14:15:53 hudba volumio[3304410]: info: MYVOLUMIO Environment detected Apr 11 14:15:53 hudba volumio[3304410]: info: Plugin folders cleanup Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning into folder /volumio/app/plugins/ Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category audio_interface Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category miscellanea Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category music_service Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category plugins.json Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category system_controller Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category user_interface Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning into folder /data/plugins/ Apr 11 14:15:53 hudba volumio[3304410]: info: Scanning category music_service Apr 11 14:15:53 hudba volumio[3304410]: info: Plugin folders cleanup completed Apr 11 14:15:53 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:15:53 hudba volumio[3304410]: info: ----- Core plugins startup ---- Apr 11 14:15:53 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:15:53 hudba volumio[3304410]: info: Loading plugins from folder /volumio/app/plugins/ Apr 11 14:15:53 hudba volumio[3304410]: info: Adding plugin upnp to MyMusic Plugins Apr 11 14:15:53 hudba volumio[3304410]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 11 14:15:53 hudba volumio[3304410]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 11 14:15:53 hudba volumio[3304410]: info: Loading plugins from folder /data/plugins/ Apr 11 14:15:53 hudba volumio[3304410]: info: Loading plugin "system"... Apr 11 14:15:53 hudba volumio[3304410]: info: Loading plugin "appearance"... Apr 11 14:15:54 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Apr 11 14:15:54 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:54 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:54 hudba go-librespot[3304442]: go-librespot daemon starting... Apr 11 14:15:54 hudba go-librespot[3304443]: time="2026-04-11T14:15:54+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:54 hudba go-librespot[3304443]: time="2026-04-11T14:15:54+02:00" level=debug msg="app state loaded" Apr 11 14:15:54 hudba go-librespot[3304443]: time="2026-04-11T14:15:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:54 hudba go-librespot[3304443]: time="2026-04-11T14:15:54+02: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" Apr 11 14:15:54 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:54 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "network"... Apr 11 14:15:54 hudba volumio[3304410]: info: Refreshing Cached IP Addresses Apr 11 14:15:54 hudba sudo[3304453]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 14:15:54 hudba sudo[3304453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:54 hudba sudo[3304453]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "services"... Apr 11 14:15:54 hudba sudo[3304455]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "volumio5onboarding"... Apr 11 14:15:54 hudba sudo[3304455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:54 hudba sudo[3304463]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 14:15:54 hudba sudo[3304463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:54 hudba sudo[3304455]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "alsa_controller"... Apr 11 14:15:54 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "wizard"... Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "networkfs"... Apr 11 14:15:54 hudba volumio[3304410]: info: Starting Udev Watcher for removable devices Apr 11 14:15:54 hudba volumio[3304410]: info: Ignoring mount for partition: boot Apr 11 14:15:54 hudba volumio[3304410]: info: Ignoring mount for partition: volumio Apr 11 14:15:54 hudba volumio[3304410]: info: Ignoring mount for partition: volumio_data Apr 11 14:15:54 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "volumio_command_line_client"... Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "upnp"... Apr 11 14:15:54 hudba volumio[3304410]: info: [1775909754626] Starting Upmpd Daemon Apr 11 14:15:54 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "my_music"... Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "mpd"... Apr 11 14:15:54 hudba volumio[3304410]: info: Loading plugin "upnp_browser"... Apr 11 14:15:56 hudba volumio[3304410]: info: Starting UPNP Browser Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "alarm-clock"... Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "airplay_emulation"... Apr 11 14:15:56 hudba volumio[3304410]: info: Starting Shairport Sync Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "last_100"... Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "webradio"... Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "i2s_dacs"... Apr 11 14:15:56 hudba volumio[3304410]: info: I2S DAC not set, start Auto-detection Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "volumiodiscovery"... Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** For more information see Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 14:15:56 hudba volumio[3304410]: *** WARNING *** For more information see Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** For more information see Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 14:15:56 hudba node[3304410]: *** WARNING *** For more information see Apr 11 14:15:56 hudba volumio[3304410]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 14:15:56 hudba volumio[3304410]: info: Discovery: Started advertising with name: Hudba Apr 11 14:15:56 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 14:15:56 hudba volumio[3304410]: info: Loading plugin "spop"... Apr 11 14:15:56 hudba volumio-remote-updater[793]: [2026-04-11 14:15:56] [connect] Successful connection Apr 11 14:15:57 hudba dhcpcd[806]: wlan0: probing address 192.168.0.105/24 Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "outputs"... Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "albumart"... Apr 11 14:15:57 hudba volumio[3304410]: info: Plugin example_plugin is not enabled Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "inputs"... Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "updater_comm"... Apr 11 14:15:57 hudba volumio[3304410]: info: Plugin mpdemulation is not enabled Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "rest_api"... Apr 11 14:15:57 hudba volumio[3304410]: info: Loading plugin "websocket"... Apr 11 14:15:57 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Apr 11 14:15:57 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:57 hudba volumio[3304410]: info: Starting Socket.io Server version 1.7.4 Apr 11 14:15:57 hudba volumio[3304410]: info: Loading i18n strings for locale sk Apr 11 14:15:57 hudba volumio[3304410]: Updating browse sources language Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 14:15:57 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:57 hudba go-librespot[3304498]: go-librespot daemon starting... Apr 11 14:15:57 hudba volumio[3304487]: Forking 3 albumart workers Apr 11 14:15:57 hudba go-librespot[3304499]: time="2026-04-11T14:15:57+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:15:57 hudba go-librespot[3304499]: time="2026-04-11T14:15:57+02:00" level=debug msg="app state loaded" Apr 11 14:15:57 hudba go-librespot[3304499]: time="2026-04-11T14:15:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:15:57 hudba go-librespot[3304499]: time="2026-04-11T14:15:57+02: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" Apr 11 14:15:57 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:15:57 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::initPlayerControls Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: Express server listening on port 3000 Apr 11 14:15:57 hudba volumio[3304410]: [Metrics] WebUI: 4s 900.36ms Apr 11 14:15:57 hudba volumio[3304410]: info: Setting Device type: x86 Apr 11 14:15:57 hudba volumio[3304410]: info: CoreStateMachine::resetVolumioState Apr 11 14:15:57 hudba volumio[3304410]: info: CoreStateMachine::getcurrentVolume Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:57 hudba volumio[3304410]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 11 14:15:57 hudba volumio[3304410]: info: Completed loading Core Plugins Apr 11 14:15:57 hudba volumio[3304410]: info: Preparing to generate the ALSA configuration file Apr 11 14:15:57 hudba volumio[3304410]: info: Cannot read play queue from file Apr 11 14:15:57 hudba volumio[3304410]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 11 14:15:57 hudba volumio[3304410]: info: Reading ALSA contributions from plugins. Apr 11 14:15:57 hudba volumio[3304410]: info: Volumio Network Manager: Network status updated: 0 Apr 11 14:15:57 hudba volumio[3304410]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 11 14:15:57 hudba volumio[3304410]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 11 14:15:57 hudba volumio[3304410]: info: CoreStateMachine::pushState Apr 11 14:15:57 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::volumioPushState Apr 11 14:15:57 hudba volumio[3304410]: info: CoreStateMachine::updateTrackBlock Apr 11 14:15:57 hudba volumio[3304410]: info: CorePlayQueue::getTrackBlock Apr 11 14:15:57 hudba volumio[3304410]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 14:15:57 hudba volumio[3304410]: 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 Apr 11 14:15:57 hudba volumio[3304410]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 11 14:15:57 hudba sudo[3304463]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:58 hudba volumio[3304410]: info: CoreStateMachine::pushState Apr 11 14:15:58 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioPushState Apr 11 14:15:58 hudba volumio[3304410]: info: CoreStateMachine::setRepeat null single undefined Apr 11 14:15:58 hudba volumio[3304410]: info: CoreStateMachine::pushState Apr 11 14:15:58 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioPushState Apr 11 14:15:58 hudba volumio[3304410]: info: CoreStateMachine::setRandom null Apr 11 14:15:58 hudba volumio[3304410]: info: CoreStateMachine::pushState Apr 11 14:15:58 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioPushState Apr 11 14:15:58 hudba volumio-remote-updater[793]: [2026-04-11 14:15:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1775909756 101 Apr 11 14:15:58 hudba volumio[3304410]: 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: 3 Apr 11 14:15:58 hudba volumio[3304410]: 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: 4 Apr 11 14:15:58 hudba volumio[3304410]: 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: 4 Apr 11 14:15:58 hudba volumio[3304410]: info: Received Get System Info Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:58 hudba volumio[3304410]: info: Discovery: Getting this device information Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:58 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:58 hudba volumio[3304410]: info: Received Get System Info Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:58 hudba volumio[3304410]: info: Discovery: Getting this device information Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:58 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:58 hudba volumio[3304410]: info: Asound.conf file unchanged, so no further update is needed Apr 11 14:15:58 hudba volumio[3304410]: info: Output device has changed, restarting MPD Apr 11 14:15:58 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:58.170+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:58 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:58.175+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:58 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:58.184+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:58 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:58.187+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:58 hudba sudo[3304557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 14:15:58 hudba sudo[3304557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:58 hudba volumio[3304410]: info: Output device has changed, restarting Shairport Sync Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:58 hudba sudo[3304557]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:58 hudba volumio[3304410]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 14:15:58 hudba volumio[3304410]: info: ___________ START PLUGINS ___________ Apr 11 14:15:58 hudba sudo[3304559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 14:15:58 hudba sudo[3304559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:58 hudba volumio[3304410]: info: ControllerMpd::onStart: Initializing MPD Apr 11 14:15:58 hudba volumio[3304410]: info: Creating MPD Configuration file Apr 11 14:15:58 hudba sudo[3304568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 11 14:15:58 hudba sudo[3304568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:58 hudba systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 14:15:58 hudba volumio[3304410]: info: [1775909758393] CoreMusicLibrary::Adding element Mediálne servery Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 14:15:58 hudba sudo[3304570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 14:15:58 hudba sudo[3304570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:58 hudba volumio[3304410]: info: UPNP Browser: Client initialized successfully Apr 11 14:15:58 hudba sudo[3304570]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:58 hudba systemd[1]: mpd.service: Deactivated successfully. Apr 11 14:15:58 hudba systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 14:15:58 hudba systemd[1]: mpd.service: Consumed 2.250s CPU time. Apr 11 14:15:58 hudba systemd[1]: mpd.socket: Deactivated successfully. Apr 11 14:15:58 hudba systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 14:15:58 hudba systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 14:15:58 hudba sudo[3304573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 14:15:58 hudba sudo[3304573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:58 hudba volumio[3304504]: Starting albumart workers Apr 11 14:15:58 hudba systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 14:15:58 hudba systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 14:15:58 hudba volumio[3304410]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:58 hudba systemd[1]: mpd.service: Deactivated successfully. Apr 11 14:15:58 hudba systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 14:15:58 hudba systemd[1]: mpd.socket: Deactivated successfully. Apr 11 14:15:58 hudba systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 14:15:58 hudba systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 14:15:58 hudba volumio[3304508]: Starting albumart workers Apr 11 14:15:58 hudba volumio[3304410]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 14:15:58 hudba volumio[3304410]: info: [1775909758637] CoreMusicLibrary::Adding element Last_100 Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 14:15:58 hudba volumio[3304410]: info: [1775909758641] CoreMusicLibrary::Adding element Webradio Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 14:15:58 hudba volumio[3304410]: info: Initializing BBC Radios Apr 11 14:15:58 hudba systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 14:15:58 hudba systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 14:15:58 hudba sudo[3304568]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:58 hudba volumio[3304506]: Starting albumart workers Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:58 hudba volumio[3304410]: info: Creating Spotify config file Apr 11 14:15:58 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:58 hudba sudo[3304589]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 14:15:58 hudba sudo[3304589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 14:15:58 hudba sudo[3304589]: pam_unix(sudo:session): session closed for user root Apr 11 14:15:59 hudba volumio[3304410]: info: Volumio Calling Home Apr 11 14:15:59 hudba volumio[3304410]: info: Discovery: adding ae412730-5e6a-429a-9912-105bacee40ef Apr 11 14:15:59 hudba volumio[3304410]: info: Discovery: Found device Hudba Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:59 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:59 hudba volumio[3304410]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Apr 11 14:15:59 hudba volumio[3304410]: Unhandled rejection Error: No sockets available, cannot start. Apr 11 14:15:59 hudba volumio[3304410]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 11 14:15:59 hudba volumio[3304410]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 11 14:15:59 hudba volumio[3304410]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 11 14:15:59 hudba volumio[3304410]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 11 14:15:59 hudba volumio[3304410]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 11 14:15:59 hudba volumio[3304410]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 11 14:15:59 hudba volumio[3304410]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 11 14:15:59 hudba volumio[3304410]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 11 14:15:59 hudba volumio[3304410]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Apr 11 14:15:59 hudba volumio[3304410]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 11 14:15:59 hudba volumio[3304410]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 11 14:15:59 hudba volumio[3304410]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 11 14:15:59 hudba volumio[3304410]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 11 14:15:59 hudba volumio[3304410]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 11 14:15:59 hudba volumio[3304410]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 11 14:15:59 hudba volumio[3304410]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 11 14:15:59 hudba volumio[3304410]: info: Received Get System Info Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:15:59 hudba volumio[3304410]: info: Discovery: Getting this device information Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:15:59 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:15:59 hudba volumio[3304410]: info: MPD Permissions set Apr 11 14:15:59 hudba volumio[3304410]: info: MPD Permissions set Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:15:59 hudba volumio[3304410]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 11 14:15:59 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:59.897+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:15:59 hudba volumio[3304410]: info: Spotify config file written Apr 11 14:15:59 hudba volumio5-onboarding[2325]: time=2026-04-11T14:15:59.903+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:15:59 hudba sudo[3304627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 14:15:59 hudba sudo[3304627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:15:59 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:15:59 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 11 14:16:00 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:16:00 hudba go-librespot[3304634]: go-librespot daemon starting... Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba sudo[3304627]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba go-librespot[3304638]: time="2026-04-11T14:16:00+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:16:00 hudba go-librespot[3304638]: time="2026-04-11T14:16:00+02:00" level=debug msg="app state loaded" Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 11 14:16:00 hudba go-librespot[3304638]: time="2026-04-11T14:16:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 14:16:00 hudba go-librespot[3304638]: time="2026-04-11T14:16:00+02: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" Apr 11 14:16:00 hudba volumio[3304410]: info: No need to fix Spotify hosts Apr 11 14:16:00 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:16:00 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:16:00 hudba volumio[3304410]: info: Starting Shairport Sync Apr 11 14:16:00 hudba volumio[3304410]: info: Starting Shairport Sync Apr 11 14:16:00 hudba volumio[3304410]: info: Starting Shairport Sync Apr 11 14:16:00 hudba sudo[3304655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 14:16:00 hudba sudo[3304655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:00 hudba sudo[3304657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 14:16:00 hudba sudo[3304657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:00 hudba sudo[3304659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 14:16:00 hudba sudo[3304659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:00 hudba systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 14:16:00 hudba systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 14:16:00 hudba systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 14:16:00 hudba systemd[1]: shairport-sync.service: Consumed 30.082s CPU time. Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:00 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:00 hudba systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 14:16:00 hudba sudo[3304657]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba volumio[3304410]: info: Shairport-Sync Started Apr 11 14:16:00 hudba sudo[3304655]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba volumio[3304410]: Error adding Membership: Error: addMembership EINVAL Apr 11 14:16:00 hudba systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 14:16:00 hudba systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 14:16:00 hudba systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 14:16:00 hudba volumio[3304410]: info: Shairport-Sync Started Apr 11 14:16:00 hudba systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 14:16:00 hudba sudo[3304659]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba volumio[3304410]: info: Shairport-Sync Started Apr 11 14:16:00 hudba mpd[3304602]: 2026-04-11T14:16:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 14:16:00 hudba systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 14:16:00 hudba sudo[3304573]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba sudo[3304559]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:00 hudba volumio[3304410]: info: Completed starting Core Plugins Apr 11 14:16:00 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:16:00 hudba volumio[3304410]: info: ----- MyVolumio plugins startup ---- Apr 11 14:16:00 hudba volumio[3304410]: info: ------------------------------------------- Apr 11 14:16:00 hudba volumio[3304410]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 14:16:00 hudba volumio[3304410]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 11 14:16:00 hudba volumio[3304410]: error: MPD error: The expression evaluated to a falsy value: Apr 11 14:16:00 hudba volumio[3304410]: assert.ok(self.idling) Apr 11 14:16:00 hudba volumio[3304410]: error: The expression evaluated to a falsy value: Apr 11 14:16:00 hudba volumio[3304410]: assert.ok(self.idling) Apr 11 14:16:00 hudba volumio[3304410]: info: MPD running with PID3304602 Apr 11 14:16:00 hudba volumio[3304410]: ,establishing connection Apr 11 14:16:00 hudba volumio[3304410]: error: MPD error: The expression evaluated to a falsy value: Apr 11 14:16:00 hudba volumio[3304410]: assert.ok(self.idling) Apr 11 14:16:00 hudba volumio[3304410]: error: The expression evaluated to a falsy value: Apr 11 14:16:00 hudba volumio[3304410]: assert.ok(self.idling) Apr 11 14:16:00 hudba volumio[3304410]: error: updateQueue error: null Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:00 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:00 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 14:16:00 hudba volumio[3304410]: info: Received Get System Info Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:16:00 hudba volumio[3304410]: info: Discovery: Getting this device information Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:00 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:16:00 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:00 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:01 hudba volumio[3304410]: info: Listing playlists Apr 11 14:16:01 hudba volumio5-onboarding[2325]: time=2026-04-11T14:16:01.100+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:16:02 hudba dhcpcd[806]: wlan0: leased 192.168.0.105 for 7200 seconds Apr 11 14:16:02 hudba avahi-daemon[1510]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.105. Apr 11 14:16:02 hudba avahi-daemon[1510]: New relevant interface wlan0.IPv4 for mDNS. Apr 11 14:16:02 hudba avahi-daemon[1510]: Registering new address record for 192.168.0.105 on wlan0.IPv4. Apr 11 14:16:02 hudba dhcpcd[806]: wlan0: adding route to 192.168.0.0/24 Apr 11 14:16:02 hudba dhcpcd[806]: wlan0: adding default route via 192.168.0.1 Apr 11 14:16:02 hudba systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:16:02 hudba systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 11 14:16:02 hudba systemd[1]: welcome.service: Deactivated successfully. Apr 11 14:16:02 hudba systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 11 14:16:02 hudba systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 11 14:16:02 hudba systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 11 14:16:02 hudba welcome[3304698]: Resolved ip:[1] 192.168.0.105 Apr 11 14:16:02 hudba systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 11 14:16:02 hudba systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 11 14:16:02 hudba volumio[3304410]: info: Received Get System Info Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 14:16:02 hudba volumio[3304410]: info: Discovery: Getting this device information Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:02 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 14:16:02 hudba volumio[3304410]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 14:16:02 hudba volumio5-onboarding[2325]: time=2026-04-11T14:16:02.567+02:00 level=INFO msg="enabling BLE discovery" Apr 11 14:16:02 hudba volumio5-onboarding[2325]: time=2026-04-11T14:16:02.569+02:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Apr 11 14:16:03 hudba volumio[3304410]: info: go-librespot daemon successfully initialized Apr 11 14:16:03 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Apr 11 14:16:03 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:16:03 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 14:16:03 hudba go-librespot[3304716]: go-librespot daemon starting... Apr 11 14:16:03 hudba go-librespot[3304717]: time="2026-04-11T14:16:03+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 14:16:03 hudba go-librespot[3304717]: time="2026-04-11T14:16:03+02:00" level=debug msg="app state loaded" Apr 11 14:16:03 hudba go-librespot[3304717]: time="2026-04-11T14:16:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 14:16:03 hudba volumio5-onboarding[2325]: time=2026-04-11T14:16:03.498+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 14:16:03 hudba ntpd[1119]: IO: Listen normally on 1507 wlan0 192.168.0.105:123 Apr 11 14:16:03 hudba ntpd[1119]: IO: new interface(s) found: waking up resolver Apr 11 14:16:03 hudba volumio[3304410]: info: Discovery: this is already registered, ae412730-5e6a-429a-9912-105bacee40ef Apr 11 14:16:03 hudba volumio[3304410]: info: Discovery: Found device Hudba Apr 11 14:16:03 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:03 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:03 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-BEACON-LOSS Apr 11 14:16:04 hudba volumio[3304410]: info: Volumio Network Manager: Network status updated: 2 Apr 11 14:16:04 hudba sudo[3304741]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 14:16:04 hudba sudo[3304741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:04 hudba sudo[3304741]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:04 hudba sudo[3304743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 14:16:04 hudba sudo[3304743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:04 hudba sudo[3304743]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:04 hudba sudo[3304746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 14:16:04 hudba sudo[3304746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 14:16:04 hudba sudo[3304746]: pam_unix(sudo:session): session closed for user root Apr 11 14:16:04 hudba volumio[3304410]: info: Upmpdcli Daemon Started Apr 11 14:16:05 hudba volumio[3304410]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 11 14:16:06 hudba volumio[3304410]: info: Initializing connection to go-librespot Websocket Apr 11 14:16:06 hudba go-librespot[3304717]: time="2026-04-11T14:16:06+02:00" level=debug msg="new websocket client" Apr 11 14:16:06 hudba volumio[3304410]: info: Connection to go-librespot Websocket established Apr 11 14:16:08 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-BEACON-LOSS Apr 11 14:16:09 hudba volumio[3304410]: info: Getting Spotify volume Apr 11 14:16:09 hudba volumio[3304410]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 11 14:16:09 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:09 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:09 hudba volumio[3304410]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 11 14:16:09 hudba volumio[3304410]: SPOTIFY: SPOTIFY VOLUME undefined Apr 11 14:16:09 hudba volumio[3304410]: SPOTIFY: VOLUMIO VOLUME 40 Apr 11 14:16:09 hudba volumio[3304410]: info: Aligning Spotify Volume to Volumio Volume Apr 11 14:16:09 hudba volumio[3304410]: info: CoreCommandRouter::volumioGetState Apr 11 14:16:09 hudba volumio[3304410]: info: CorePlayQueue::getTrack 0 Apr 11 14:16:09 hudba volumio[3304410]: info: Setting Spotify Volume from Volumio: 40 Apr 11 14:16:09 hudba volumio[3304410]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=ee3102c61c99d2809dc3d08548163f67" http://updates.volumio.org/downloader-v1/track-device Apr 11 14:16:09 hudba volumio[3304410]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 11 14:16:09 hudba volumio[3304410]: Dload Upload Total Spent Left Speed Apr 11 14:16:09 hudba volumio[3304410]: [132B blob data] Apr 11 14:16:09 hudba volumio[3304410]: retrying in 5 seconds, trial 0 Apr 11 14:16:09 hudba volumio[3304410]: info: Volumio Calling Home Apr 11 14:16:10 hudba volumio[3304410]: SPOTIFY: SETTING SPOTIFY VOLUME 40 Apr 11 14:16:10 hudba volumio[3304410]: info: Sending Spotify command with payload to local API: /player/volume Apr 11 14:16:10 hudba volumio[3304410]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Apr 11 14:16:14 hudba go-librespot[3304717]: time="2026-04-11T14:16:14+02: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\": net/http: TLS handshake timeout" Apr 11 14:16:14 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 14:16:14 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 14:16:14 hudba volumio[3304410]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 14:16:14 hudba volumio[3304410]: Error: socket hang up Apr 11 14:16:14 hudba volumio[3304410]: at connResetException (node:internal/errors:720:14) Apr 11 14:16:14 hudba volumio[3304410]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 11 14:16:14 hudba volumio[3304410]: at Socket.emit (node:events:526:35) Apr 11 14:16:14 hudba volumio[3304410]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 11 14:16:14 hudba volumio[3304410]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 11 14:16:14 hudba volumio[3304410]: code: 'ECONNRESET', Apr 11 14:16:14 hudba volumio[3304410]: response: undefined Apr 11 14:16:14 hudba volumio[3304410]: } Apr 11 14:16:14 hudba volumio[3304410]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 14:16:14 hudba sudo[3304779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 14:15' Apr 11 14:16:14 hudba sudo[3304779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"