Mar 29 07:00:10 volumio go-librespot[1295]: time="2026-03-29T07:00:10+02:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.3:41140->34.158.255.62:4070: read: connection timed out" Mar 29 07:00:11 volumio go-librespot[1295]: time="2026-03-29T07:00:11+02:00" level=debug msg="renewing login5 access token" Mar 29 07:00:15 volumio go-librespot[1295]: time="2026-03-29T07:00:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 29 07:00:21 volumio go-librespot[1295]: time="2026-03-29T07:00:21+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 29 07:00:21 volumio go-librespot[1295]: fatal error: runtime: out of memory Mar 29 07:00:21 volumio kernel: __vm_enough_memory: pid: 1299, comm: go-librespot, bytes: 1216348160 not enough memory for the allocation Mar 29 07:00:21 volumio go-librespot[1295]: runtime stack: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.throw({0x925f51, 0x16}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/panic.go:1094 +0x34 fp=0x75ffec34 sp=0x75ffec20 pc=0xa9680 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.sysMapOS(0x23400000, 0x48800000, {0x919b1f, 0x4}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mem_linux.go:175 +0x17c fp=0x75ffec60 sp=0x75ffec34 pc=0x4330c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.sysMap(0x23400000, 0x48800000, 0x1006568, {0x919b1f, 0x4}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mem.go:178 +0x50 fp=0x75ffec74 sp=0x75ffec60 pc=0x42b5c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*mheap).grow(0x1000800, 0x242a3) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mheap.go:1616 +0x2e4 fp=0x75ffecc8 sp=0x75ffec74 pc=0x5c244 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*mheap).allocSpan(0x1000800, 0x242a3, 0x0, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mheap.go:1299 +0x1d8 fp=0x75ffed54 sp=0x75ffecc8 pc=0x5b644 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*mheap).alloc.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mheap.go:1017 +0x84 fp=0x75ffed78 sp=0x75ffed54 pc=0x5b100 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.systemstack(0x1000000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:315 +0x60 fp=0x75ffed7c sp=0x75ffed78 pc=0xaebf0 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 140 gp=0x30fd568 m=3 mp=0x304d008 [running]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.systemstack_switch() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:272 +0x4 fp=0x305cc3c sp=0x305cc38 pc=0xaeb84 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*mheap).alloc(0x1000800, 0x242a3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mheap.go:1011 +0x58 fp=0x305cc5c sp=0x305cc3c pc=0x5b05c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*mcache).allocLarge(0x76ca1548, 0x4854544c, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mcache.go:236 +0x70 fp=0x305cc88 sp=0x305cc5c pc=0x3f8d0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.mallocgcLarge(0x4854544c, 0x804990, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/malloc.go:1552 +0x8c fp=0x305ccbc sp=0x305cc88 pc=0x3c6c8 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.mallocgc(0x4854544c, 0x804990, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/malloc.go:1072 +0x128 fp=0x305ccd8 sp=0x305ccbc pc=0xa6f70 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.makeslice(0x804990, 0x4854544c, 0x4854544c) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/slice.go:116 +0x9c fp=0x305ccec sp=0x305ccd8 pc=0xabe18 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.readMessage({0xa39ec8, 0x342c5c0}, 0xffffffff, {0xa39e58, 0x342c5e0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/conn.go:53 +0x158 fp=0x305cd28 sp=0x305ccec pc=0x4f9d60 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).performKeyExchange(0x30be638) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:443 +0x440 fp=0x305cd80 sp=0x305cd28 pc=0x4f8638 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).connect(0x30be638, {0xa3da1c, 0x1005090}, 0x313d860) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:215 +0x17c fp=0x305cde4 sp=0x305cd80 pc=0x4f6b00 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect(0x30be638) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:394 +0xcc fp=0x305ce0c sp=0x305cde4 pc=0x4f8018 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect-fm() Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x28 fp=0x305ce1c sp=0x305ce0c pc=0x4fc270 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.Operation.withEmptyData.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:18 +0x1c fp=0x305ce28 sp=0x305ce1c pc=0x4eb1c8 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x305cecc, {0xa3c8c0, 0x3314300}, 0x0, {0x0, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:88 +0xcc fp=0x305cea4 sp=0x305ce28 pc=0x4eb644 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x305cf5c, {0xa3c8c0, 0x3314300}, 0x0, {0x0, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x5c fp=0x305ced4 sp=0x305cea4 pc=0x4eb180 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotify(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.Retry(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0x30be638) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:335 +0x434 fp=0x305cfe4 sp=0x305ced4 pc=0x4f7878 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:403 +0x28 fp=0x305cfec sp=0x305cfe4 pc=0x4f81cc Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x305cfec sp=0x305cfec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).reconnect in goroutine 115 Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:403 +0x120 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 1 gp=0x3002128 m=nil [select, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3477ce0 sp=0x3477ccc pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x3477df0, 0x323bdbc, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x3477d90 sp=0x3477ce0 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x30f52c0, 0x3477e90) Mar 29 07:00:21 volumio go-librespot[1295]: /src/zeroconf/zeroconf.go:300 +0x228 fp=0x3477e38 sp=0x3477d90 pc=0x62f43c Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).withAppPlayer(0x3188580, {0xa3da1c, 0x1005090}, 0x3011530) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:340 +0x5dc fp=0x3477ed0 sp=0x3477e38 pc=0x6bcc60 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).withCredentials(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:209 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).SpotifyToken(0x3188580, {0xa3da1c, 0x1005090}, {0x318e820, 0x19}, {0x3234000, 0x13a}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:201 +0xc0 fp=0x3477f00 sp=0x3477ed0 pc=0x6bc02c Mar 29 07:00:21 volumio go-librespot[1295]: main.main() Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:620 +0x660 fp=0x3477fa8 sp=0x3477f00 pc=0x6bf56c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.main() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:285 +0x2f0 fp=0x3477fec sp=0x3477fa8 pc=0x6f390 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3477fec sp=0x3477fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 2 gp=0x30027e8 m=nil [force gc (idle), 2 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97746c, 0xff8fa8, 0x11, 0xa, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3048fd4 sp=0x3048fc0 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goparkunlock(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:466 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.forcegchelper() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:373 +0xe4 fp=0x3048fec sp=0x3048fd4 pc=0x6f7f4 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3048fec sp=0x3048fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.init.6 in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:361 +0x1c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 18 gp=0x3082248 m=nil [GC sweep wait]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97746c, 0xff9850, 0xc, 0x9, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x30447c4 sp=0x30447b0 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goparkunlock(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:466 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.bgsweep(0x3090000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgcsweep.go:323 +0x11c fp=0x30447e4 sp=0x30447c4 pc=0x5768c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcenable.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:212 +0x28 fp=0x30447ec sp=0x30447e4 pc=0x46c3c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x30447ec sp=0x30447ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcenable in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:212 +0x74 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 19 gp=0x3082368 m=nil [GC scavenge wait]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97746c, 0xffa170, 0xd, 0xa, 0x2) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3044fb4 sp=0x3044fa0 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goparkunlock(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:466 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*scavengerState).park(0xffa170) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x3044fc8 sp=0x3044fb4 pc=0x54a28 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.bgscavenge(0x3090000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x3044fe4 sp=0x3044fc8 pc=0x5516c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcenable.gowrap2() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:213 +0x28 fp=0x3044fec sp=0x3044fe4 pc=0x46be8 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3044fec sp=0x3044fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcenable in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:213 +0xbc Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 20 gp=0x3082488 m=nil [GOMAXPROCS updater (idle), 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97746c, 0xff95e8, 0x12, 0xa, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x30457a4 sp=0x3045790 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goparkunlock(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:466 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.updateMaxProcsGoroutine() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:6720 +0x110 fp=0x30457ec sp=0x30457a4 pc=0x7f174 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x30457ec sp=0x30457ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.defaultGOMAXPROCSUpdateEnable in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:6708 +0x40 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 3 gp=0x3002d88 m=nil [finalizer wait, 1573 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x977314, 0x1005180, 0x10, 0xa, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3049788 sp=0x3049774 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.runFinalizers() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mfinal.go:210 +0x110 fp=0x30497ec sp=0x3049788 pc=0x45888 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x30497ec sp=0x30497ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.createfing in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mfinal.go:172 +0x5c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 21 gp=0x30fc908 m=nil [cleanup wait]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97746c, 0xffa348, 0x2e, 0xa, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3045fa4 sp=0x3045f90 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goparkunlock(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:466 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.(*cleanupQueue).dequeue(0xffa2e8) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mcleanup.go:439 +0x12c fp=0x3045fc4 sp=0x3045fa4 pc=0x41cb0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.runCleanups() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mcleanup.go:635 +0x7c fp=0x3045fec sp=0x3045fc4 pc=0x4284c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3045fec sp=0x3045fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.(*cleanupQueue).createGs in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mcleanup.go:589 +0x124 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 6 gp=0x321f208 m=nil [IO wait, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97745c, 0x76132e10, 0x2, 0x2, 0x5) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x304a4f0 sp=0x304a4dc pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.netpollblock(0x76132e00, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x304a508 sp=0x304a4f0 pc=0x675a0 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.runtime_pollWait(0x76132e00, 0x72) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x304a51c sp=0x304a508 pc=0xa8864 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).wait(0x31d72d8, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x304a530 sp=0x304a51c pc=0x136044 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).waitRead(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*FD).Accept(0x31d72c0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x304a578 sp=0x304a530 pc=0x13a800 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*netFD).accept(0x31d72c0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x304a5e0 sp=0x304a578 pc=0x1abc28 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*TCPListener).accept(0x3000570) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x304a634 sp=0x304a5e0 pc=0x1c3554 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*TCPListener).Accept(0x3000570) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x304a650 sp=0x304a634 pc=0x1c259c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*onceCloseListener).Accept(0x310cb80) Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x34 fp=0x304a668 sp=0x304a650 pc=0x367f9c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Server).Serve(0x3164008, {0xa3d218, 0x3000570}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x304a700 sp=0x304a668 pc=0x341154 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.Serve(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2971 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*ConcreteApiServer).serve(0x302a660) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/api_server.go:666 +0x974 fp=0x304a7e4 sp=0x304a700 pc=0x6b17bc Mar 29 07:00:21 volumio go-librespot[1295]: main.NewApiServer.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/api_server.go:332 +0x28 fp=0x304a7ec sp=0x304a7e4 pc=0x6b04f4 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x304a7ec sp=0x304a7ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by main.NewApiServer in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/api_server.go:332 +0x310 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 71 gp=0x321f328 m=nil [select, 146 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3171930 sp=0x317191c pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x3171f70, 0x3171b20, 0x0, 0x0, 0xa, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x31719e0 sp=0x3171930 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*AppPlayer).Run(0x333c3c0, {0xa3da1c, 0x1005090}, 0x323e300, 0x323e340) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/player.go:661 +0x368 fp=0x3171fd4 sp=0x31719e0 pc=0x6c5950 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).withAppPlayer.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:274 +0x48 fp=0x3171fec sp=0x3171fd4 pc=0x6bd9f0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3171fec sp=0x3171fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by main.(*App).withAppPlayer in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:274 +0x46c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 72 gp=0x321f568 m=nil [chan receive, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9772f4, 0x31921b8, 0xe, 0x7, 0x2) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34f8f3c sp=0x34f8f28 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv(0x3192180, 0x34f8fd0, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x34f8f84 sp=0x34f8f3c pc=0x3414c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv2(0x3192180, 0x34f8fd0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x34f8f98 sp=0x34f8f84 pc=0x33bf0 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).withAppPlayer.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:284 +0x68 fp=0x34f8fec sp=0x34f8f98 pc=0x6bd918 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34f8fec sp=0x34f8fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by main.(*App).withAppPlayer in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:281 +0x4f8 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 35 gp=0x3150248 m=nil [chan receive, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9772f4, 0x350dd78, 0xe, 0x7, 0x2) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3049f78 sp=0x3049f64 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv(0x350dd40, 0x0, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x3049fc0 sp=0x3049f78 pc=0x3414c Mar 29 07:00:21 volumio volumio[995]: info: Connection to go-librespot Websocket closed Mar 29 07:00:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv1(0x350dd40, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:509 +0x20 fp=0x3049fd4 sp=0x3049fc0 pc=0x33bcc Mar 29 07:00:21 volumio go-librespot[1295]: github.com/godbus/dbus/v5.newConn.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:303 +0x40 fp=0x3049fec sp=0x3049fd4 pc=0x4aa8ec Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3049fec sp=0x3049fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/godbus/dbus/v5.newConn in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:302 +0x52c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 11 gp=0x321f7a8 m=nil [GC worker (idle)]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x977320, 0x3230600, 0x1c, 0xa, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34fbf88 sp=0x34fbf74 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkWorker(0x3192a40) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x34fbfe4 sp=0x34fbf88 pc=0x49f34 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkStartWorkers.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x34fbfec sp=0x34fbfe4 pc=0x49e14 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34fbfec sp=0x34fbfec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcBgMarkStartWorkers in goroutine 9 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 12 gp=0x321f8c8 m=nil [GC worker (idle), 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x977320, 0x3230800, 0x1c, 0xa, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x304b788 sp=0x304b774 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkWorker(0x3192a40) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x304b7e4 sp=0x304b788 pc=0x49f34 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkStartWorkers.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x304b7ec sp=0x304b7e4 pc=0x49e14 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x304b7ec sp=0x304b7ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcBgMarkStartWorkers in goroutine 9 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 13 gp=0x321f9e8 m=nil [GC worker (idle)]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x977320, 0x3230a00, 0x1c, 0xa, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3476f88 sp=0x3476f74 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkWorker(0x3192a40) Mar 29 07:00:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x3476fe4 sp=0x3476f88 pc=0x49f34 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkStartWorkers.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x3476fec sp=0x3476fe4 pc=0x49e14 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3476fec sp=0x3476fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcBgMarkStartWorkers in goroutine 9 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 14 gp=0x321fb08 m=nil [GC worker (idle), 248 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x977320, 0x3230c00, 0x1c, 0xa, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34faf88 sp=0x34faf74 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkWorker(0x3192a40) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1463 +0xf4 fp=0x34fafe4 sp=0x34faf88 pc=0x49f34 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gcBgMarkStartWorkers.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x28 fp=0x34fafec sp=0x34fafe4 pc=0x49e14 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34fafec sp=0x34fafec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by runtime.gcBgMarkStartWorkers in goroutine 9 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/mgc.go:1373 +0x14c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 212 gp=0x30fcc68 m=nil [select]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3059b60 sp=0x3059b4c pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x3059c68, 0x3059c38, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x3059c10 sp=0x3059b60 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: net.doBlockingWithCtx[...]({0xa3da54, 0x313d800}, {0x30ac300, 0x12}, 0x34e1368) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:71 +0x280 fp=0x3059c90 sp=0x3059c10 pc=0x1cd880 Mar 29 07:00:21 volumio go-librespot[1295]: net.cgoLookupIP({0xa3da54, 0x313d800}, {0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:228 +0x98 fp=0x3059cc0 sp=0x3059c90 pc=0x19d584 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).lookupIP(0xff9700, {0xa3da54, 0x313d800}, {0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/lookup_unix.go:64 +0x90 fp=0x3059efc sp=0x3059cc0 pc=0x1b8c5c Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).lookupIP-fm({0xa3da54, 0x313d800}, {0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x58 fp=0x3059f30 sp=0x3059efc pc=0x1d3574 Mar 29 07:00:21 volumio systemd[1]: go-librespot-daemon.service: Consumed 32.756s CPU time. Mar 29 07:00:21 volumio go-librespot[1295]: net.init.func1({0xa3da54, 0x313d800}, 0x350e818, {0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/hook.go:21 +0x4c fp=0x3059f60 sp=0x3059f30 pc=0x19abf8 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).lookupIPAddr.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/lookup.go:335 +0x58 fp=0x3059f9c sp=0x3059f60 pc=0x1b849c Mar 29 07:00:21 volumio go-librespot[1295]: internal/singleflight.(*Group).doCall(0xff9708, 0x313d830, {0x30ac318, 0x16}, 0x337e7a0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/singleflight/singleflight.go:93 +0x1c fp=0x3059fd4 sp=0x3059f9c pc=0x198e98 Mar 29 07:00:21 volumio go-librespot[1295]: internal/singleflight.(*Group).DoChan.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/singleflight/singleflight.go:86 +0x48 fp=0x3059fec sp=0x3059fd4 pc=0x198e50 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3059fec sp=0x3059fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by internal/singleflight.(*Group).DoChan in goroutine 211 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/singleflight/singleflight.go:86 +0x304 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 51 gp=0x321e248 m=nil [IO wait, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97745c, 0x76132810, 0x2, 0x2, 0x5) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3581cbc sp=0x3581ca8 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.netpollblock(0x76132800, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x3581cd4 sp=0x3581cbc pc=0x675a0 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.runtime_pollWait(0x76132800, 0x72) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x3581ce8 sp=0x3581cd4 pc=0xa8864 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).wait(0x31d6ec8, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x3581cfc sp=0x3581ce8 pc=0x136044 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).waitRead(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*FD).ReadMsg(0x31d6eb0, {0x336fdc0, 0x10, 0x10}, {0x31a4018, 0x1000, 0x1000}, 0x40000000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_unix.go:295 +0x2c0 fp=0x3581d6c sp=0x3581cfc pc=0x1381bc Mar 29 07:00:21 volumio go-librespot[1295]: net.(*netFD).readMsg(0x31d6eb0, {0x336fdc0, 0x10, 0x10}, {0x31a4018, 0x1000, 0x1000}, 0x40000000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/fd_posix.go:91 +0x58 fp=0x3581dc8 sp=0x3581d6c pc=0x1aa2c8 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*UnixConn).readMsg(0x3093730, {0x336fdc0, 0x10, 0x10}, {0x31a4018, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/unixsock_posix.go:115 +0x58 fp=0x3581e28 sp=0x3581dc8 pc=0x1c9d80 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*UnixConn).ReadMsgUnix(0x3093730, {0x336fdc0, 0x10, 0x10}, {0x31a4018, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/unixsock.go:143 +0x58 fp=0x3581e78 sp=0x3581e28 pc=0x1c820c Mar 29 07:00:21 volumio go-librespot[1295]: github.com/godbus/dbus/v5.(*oobReader).Read(0x31a4008, {0x336fdc0, 0x10, 0x10}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:41 +0x50 fp=0x3581ec8 sp=0x3581e78 pc=0x4c2af0 Mar 29 07:00:21 volumio go-librespot[1295]: io.ReadAtLeast({0xa39d58, 0x31a4008}, {0x336fdc0, 0x10, 0x10}, 0x10) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/io/io.go:335 +0x90 fp=0x3581ef4 sp=0x3581ec8 pc=0xee954 Mar 29 07:00:21 volumio go-librespot[1295]: io.ReadFull(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/io/io.go:354 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/godbus/dbus/v5.(*unixTransport).ReadMessage(0x30bb5c0) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/transport_unix.go:124 +0x224 fp=0x3581fa0 sp=0x3581ef4 pc=0x4c32c4 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/godbus/dbus/v5.(*Conn).inWorker(0x315e200) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/conn.go:390 +0x44 fp=0x3581fe4 sp=0x3581fa0 pc=0x4aaef4 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/godbus/dbus/v5.(*Conn).Auth.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x28 fp=0x3581fec sp=0x3581fe4 pc=0x4a8318 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3581fec sp=0x3581fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/godbus/dbus/v5.(*Conn).Auth in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/godbus/dbus/v5@v5.2.0/auth.go:118 +0x77c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 70 gp=0x31507e8 m=nil [select, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34fce74 sp=0x34fce60 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x34fcf80, 0x34fcf4c, 0x0, 0x0, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x34fcf24 sp=0x34fce74 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0x31d6dc0) Mar 29 07:00:21 volumio go-librespot[1295]: /src/player/player.go:215 +0x1f4 fp=0x34fcfe4 sp=0x34fcf24 pc=0x582954 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/player/player.go:197 +0x28 fp=0x34fcfec sp=0x34fcfe4 pc=0x58253c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34fcfec sp=0x34fcfec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/player/player.go:197 +0x220 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 213 gp=0x3150b48 m=4 mp=0x304d808 [syscall]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.cgocall(0x75ea90, 0x34fa6fc) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/cgocall.go:167 +0x50 fp=0x34fa6e4 sp=0x34fa6cc pc=0xa628c Mar 29 07:00:21 volumio go-librespot[1295]: net._C2func_getaddrinfo(0x30ac330, 0x0, 0x337e960, 0x350e890) Mar 29 07:00:21 volumio go-librespot[1295]: _cgo_gotypes.go:105 +0x44 fp=0x34fa6f8 sp=0x34fa6e4 pc=0x1caa18 Mar 29 07:00:21 volumio go-librespot[1295]: net._C_getaddrinfo.func1(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix_cgo.go:84 Mar 29 07:00:21 volumio go-librespot[1295]: net._C_getaddrinfo(0x30ac330, 0x0, 0x337e960, 0x350e890) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix_cgo.go:84 +0x80 fp=0x34fa718 sp=0x34fa6f8 pc=0x1cacdc Mar 29 07:00:21 volumio go-librespot[1295]: net.cgoLookupHostIP({0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:174 +0x1f4 fp=0x34fa78c sp=0x34fa718 pc=0x19cfe0 Mar 29 07:00:21 volumio go-librespot[1295]: net.cgoLookupIP.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:229 +0x34 fp=0x34fa7b4 sp=0x34fa78c pc=0x19d604 Mar 29 07:00:21 volumio go-librespot[1295]: net.doBlockingWithCtx[...].func1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:67 +0x54 fp=0x34fa7ec sp=0x34fa7b4 pc=0x1cdac8 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34fa7ec sp=0x34fa7ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by net.doBlockingWithCtx[...] in goroutine 212 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/cgo_unix.go:64 +0x204 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 79 gp=0x3150c68 m=nil [IO wait, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97745c, 0x7458b610, 0x2, 0x2, 0x5) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3239908 sp=0x32398f4 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.netpollblock(0x7458b600, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x3239920 sp=0x3239908 pc=0x675a0 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.runtime_pollWait(0x7458b600, 0x72) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x3239934 sp=0x3239920 pc=0xa8864 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).wait(0x31d6fb8, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x3239948 sp=0x3239934 pc=0x136044 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).waitRead(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*FD).Read(0x31d6fa0, {0x32ef000, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_unix.go:165 +0x22c fp=0x3239990 sp=0x3239948 pc=0x1371c4 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*netFD).Read(0x31d6fa0, {0x32ef000, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/fd_posix.go:68 +0x38 fp=0x32399bc sp=0x3239990 pc=0x1a9e78 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*conn).Read(0x3092c38, {0x32ef000, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/net.go:196 +0x48 fp=0x32399e8 sp=0x32399bc pc=0x1b967c Mar 29 07:00:21 volumio go-librespot[1295]: io.(*multiReader).Read(0x30bb230, {0x32ef000, 0x1000, 0x1000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x3239a14 sp=0x32399e8 pc=0xefb88 Mar 29 07:00:21 volumio go-librespot[1295]: bufio.(*Reader).fill(0x34f7e60) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/bufio/bufio.go:113 +0x10c fp=0x3239a38 sp=0x3239a14 pc=0x2b6c1c Mar 29 07:00:21 volumio go-librespot[1295]: bufio.(*Reader).ReadByte(0x34f7e60) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/bufio/bufio.go:273 +0x28 fp=0x3239a44 sp=0x3239a38 pc=0x2b7498 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.readFrameHeader(0x34f7e60, {0x31a2338, 0x8, 0x8}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/frame.go:55 +0x68 fp=0x3239a84 sp=0x3239a44 pc=0x372a08 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.(*Conn).readFrameHeader(0x31a2308, {0xa3da00, 0x1005090}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:266 +0xd0 fp=0x3239b08 sp=0x3239a84 pc=0x375bd4 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.(*Conn).readLoop(0x31a2308, {0xa3da00, 0x1005090}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:185 +0x3c fp=0x3239bcc sp=0x3239b08 pc=0x375390 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.(*Conn).reader(0x31a2308, {0xa3da00, 0x1005090}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:381 +0xec fp=0x3239c50 sp=0x3239bcc pc=0x376798 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.(*Conn).Reader(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:36 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/coder/websocket.(*Conn).Read(0x31a2308, {0xa3da00, 0x1005090}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/coder/websocket@v1.8.14/read.go:42 +0x30 fp=0x3239c78 sp=0x3239c50 pc=0x374944 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*ConcreteApiServer).serve.func17({0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/api_server.go:636 +0x3b4 fp=0x3239cfc sp=0x3239c78 pc=0x6b2040 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.HandlerFunc.ServeHTTP(0x31022c8, {0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x3239d0c sp=0x3239cfc pc=0x33d7d8 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*ServeMux).ServeHTTP(0x315e000, {0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2861 +0x228 fp=0x3239d4c sp=0x3239d0c pc=0x33f6c8 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x124 fp=0x3239d74 sp=0x3239d4c pc=0x6b19b8 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.HandlerFunc.ServeHTTP(0x3126290, {0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2322 +0x34 fp=0x3239d84 sp=0x3239d74 pc=0x33d7d8 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.serverHandler.ServeHTTP({0x3164008}, {0xa3d2d8, 0x338c6e8}, 0x338c588) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:3340 +0xe0 fp=0x3239da0 sp=0x3239d84 pc=0x35cb44 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*conn).serve(0x3527500, {0xa3da38, 0x3124438}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2109 +0x794 fp=0x3239fdc sp=0x3239da0 pc=0x33b894 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Server).Serve.gowrap3() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:3493 +0x38 fp=0x3239fec sp=0x3239fdc pc=0x3415cc Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3239fec sp=0x3239fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by net/http.(*Server).Serve in goroutine 6 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:3493 +0x42c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 86 gp=0x3150d88 m=nil [select, 2 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3580ea4 sp=0x3580e90 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x3580fd4, 0x3580f78, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x3580f54 sp=0x3580ea4 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0x30be638) Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:368 +0x8c fp=0x3580fe4 sp=0x3580f54 pc=0x4f7cf8 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap2() Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:277 +0x28 fp=0x3580fec sp=0x3580fe4 pc=0x4f73c4 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3580fec sp=0x3580fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 71 Mar 29 07:00:21 volumio go-librespot[1295]: /src/ap/ap.go:277 +0x15c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 73 gp=0x30fcfc8 m=nil [chan receive, 1575 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9772f4, 0x3192178, 0xe, 0x7, 0x2) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34f9740 sp=0x34f972c pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv(0x3192140, 0x34f97e0, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:667 +0x550 fp=0x34f9788 sp=0x34f9740 pc=0x3414c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.chanrecv2(0x3192140, 0x34f97e0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/chan.go:514 +0x20 fp=0x34f979c sp=0x34f9788 pc=0x33bf0 Mar 29 07:00:21 volumio go-librespot[1295]: main.(*App).withAppPlayer.func2() Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:300 +0x6c fp=0x34f97ec sp=0x34f979c pc=0x6bd47c Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34f97ec sp=0x34f97ec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by main.(*App).withAppPlayer in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/cmd/daemon/main.go:297 +0x598 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 74 gp=0x30fd0e8 m=nil [IO wait, 250 minutes]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x97745c, 0x76132a10, 0x2, 0x2, 0x5) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x34f9dac sp=0x34f9d98 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.netpollblock(0x76132a00, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:575 +0x100 fp=0x34f9dc4 sp=0x34f9dac pc=0x675a0 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.runtime_pollWait(0x76132a00, 0x72) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/netpoll.go:351 +0x54 fp=0x34f9dd8 sp=0x34f9dc4 pc=0xa8864 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).wait(0x31d6e78, 0x72, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x34f9dec sp=0x34f9dd8 pc=0x136044 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*pollDesc).waitRead(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Mar 29 07:00:21 volumio go-librespot[1295]: internal/poll.(*FD).Accept(0x31d6e60) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/internal/poll/fd_unix.go:613 +0x284 fp=0x34f9e34 sp=0x34f9dec pc=0x13a800 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*netFD).accept(0x31d6e60) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/fd_unix.go:161 +0x20 fp=0x34f9e9c sp=0x34f9e34 pc=0x1abc28 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*TCPListener).accept(0x322c000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x34f9ef0 sp=0x34f9e9c pc=0x1c3554 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*TCPListener).Accept(0x322c000) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/tcpsock.go:380 +0x30 fp=0x34f9f0c sp=0x34f9ef0 pc=0x1c259c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*onceCloseListener).Accept(0x3517e00) Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x34 fp=0x34f9f24 sp=0x34f9f0c pc=0x367f9c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Server).Serve(0x338c428, {0xa3d218, 0x322c000}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:3463 +0x2d8 fp=0x34f9fbc sp=0x34f9f24 pc=0x341154 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.Serve(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/server.go:2971 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Mar 29 07:00:21 volumio go-librespot[1295]: /src/zeroconf/zeroconf.go:297 +0x8c fp=0x34f9fec sp=0x34f9fbc pc=0x62f538 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x34f9fec sp=0x34f9fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Mar 29 07:00:21 volumio go-librespot[1295]: /src/zeroconf/zeroconf.go:297 +0x160 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 88 gp=0x3150fc8 m=nil [select]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x305de84 sp=0x305de70 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x305dfd4, 0x305df5c, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x305df34 sp=0x305de84 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).pingTicker(0x338c218) Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:138 +0x8c fp=0x305dfe4 sp=0x305df34 pc=0x5a1d90 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1.gowrap2() Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:129 +0x28 fp=0x305dfec sp=0x305dfe4 pc=0x5a3cd4 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x305dfec sp=0x305dfec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1 in goroutine 71 Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:129 +0x15c Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 136 gp=0x31517a8 m=nil [select]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x3237604 sp=0x32375f0 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x3237764, 0x32376dc, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x32376b4 sp=0x3237604 pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).getConn(0xfa9328, 0x313d7a0, {{}, 0x0, {0x92ae9f, 0x5}, {0x30ac300, 0x16}, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1523 +0x370 fp=0x32377b0 sp=0x32376b4 pc=0x351ccc Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).roundTrip(0xfa9328, 0x3194e78) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:685 +0x978 fp=0x323789c sp=0x32377b0 pc=0x34ddb4 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).RoundTrip(0xfa9328, 0x3194e78) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/roundtrip.go:33 +0x2c fp=0x32378b4 sp=0x323789c pc=0x35c310 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.send(0x3194d18, {0xa39338, 0xfa9328}, {0xc26a4a5e6c54f88d, 0x56054d020967, 0xff9f08}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/client.go:259 +0x53c fp=0x32379e0 sp=0x32378b4 pc=0x2edc78 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Client).send(0x3076ec0, 0x3194d18, {0xc26a4a5e6c54f88d, 0x56054d020967, 0xff9f08}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/client.go:180 +0x98 fp=0x3237a24 sp=0x32379e0 pc=0x2ed564 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Client).do(0x3076ec0, 0x3194d18) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/client.go:729 +0x9a8 fp=0x3237b34 sp=0x3237a24 pc=0x2efbcc Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Client).Do(...) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/client.go:587 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/login5.(*Login5).request(0x31d7130, {0xa3da1c, 0x1005090}, 0x313d1d0) Mar 29 07:00:21 volumio go-librespot[1295]: /src/login5/login5.go:72 +0x4b8 fp=0x3237c58 sp=0x3237b34 pc=0x5afe1c Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/login5.(*Login5).Login(0x31d7130, {0xa3da1c, 0x1005090}, {0xa39c18, 0x313d1a0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/login5/login5.go:122 +0x4b8 fp=0x3237cec sp=0x3237c58 pc=0x5b0614 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/session.NewSessionFromOptions.(*Login5).AccessToken.func2({0xa3da1c, 0x1005090}, 0x0) Mar 29 07:00:21 volumio go-librespot[1295]: /src/login5/login5.go:200 +0x1e4 fp=0x3237d88 sp=0x3237cec pc=0x5b7dc8 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).connect(0x338c218, {0xa3da1c, 0x1005090}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:82 +0xc8 fp=0x3237e1c sp=0x3237d88 pc=0x5a1844 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect(0x338c218) Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:288 +0x2c fp=0x3237e54 sp=0x3237e1c pc=0x5a2d08 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect-fm() Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x28 fp=0x3237e64 sp=0x3237e54 pc=0x5a466c Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.Operation.withEmptyData.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:18 +0x1c fp=0x3237e70 sp=0x3237e64 pc=0x4eb1c8 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x3237f14, {0xa3c8c0, 0x346a360}, 0x0, {0x0, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:88 +0xcc fp=0x3237eec sp=0x3237e70 pc=0x4eb644 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x3583f68, {0xa3c8c0, 0x346a360}, 0x0, {0x0, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61 +0x5c fp=0x3237f1c sp=0x3237eec pc=0x4eb180 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.RetryNotify(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/cenkalti/backoff/v4.Retry(...) Mar 29 07:00:21 volumio go-librespot[1295]: /src/.gocache/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:38 Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).recvLoop(0x338c218) Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:237 +0x688 fp=0x3237fe4 sp=0x3237f1c pc=0x5a285c Mar 29 07:00:21 volumio go-librespot[1295]: github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect.gowrap1() Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:296 +0x28 fp=0x3237fec sp=0x3237fe4 pc=0x5a2e88 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3237fec sp=0x3237fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect in goroutine 87 Mar 29 07:00:21 volumio go-librespot[1295]: /src/dealer/dealer.go:296 +0xf8 Mar 29 07:00:21 volumio go-librespot[1295]: goroutine 211 gp=0x321e5a8 m=nil [select]: Mar 29 07:00:21 volumio go-librespot[1295]: runtime.gopark(0x9774a0, 0x0, 0x9, 0x3, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/proc.go:460 +0x104 fp=0x305886c sp=0x3058858 pc=0xa97c0 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.selectgo(0x30589dc, 0x3058948, 0x0, 0x0, 0x2, 0x1) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/select.go:351 +0xc4c fp=0x305891c sp=0x305886c pc=0x85000 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).lookupIPAddr(0xff9700, {0xa3da8c, 0x317e690}, {0x919486, 0x3}, {0x30ac300, 0x12}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/lookup.go:343 +0x394 fp=0x3058a24 sp=0x305891c pc=0x1b7b00 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).internetAddrList(0xff9700, {0xa3da8c, 0x317e690}, {0x919486, 0x3}, {0x30ac300, 0x16}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/ipsock.go:289 +0x6b0 fp=0x3058ab8 sp=0x3058a24 pc=0x1b5abc Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Resolver).resolveAddrList(0xff9700, {0xa3da8c, 0x317e690}, {0x9198a7, 0x4}, {0x919486, 0x3}, {0x30ac300, 0x16}, {0x0, ...}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/dial.go:353 +0x510 fp=0x3058b40 sp=0x3058ab8 pc=0x1a03f8 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Dialer).DialContext(0x32aa230, {0xa3da54, 0x313d7d0}, {0x919486, 0x3}, {0x30ac300, 0x16}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/dial.go:560 +0x43c fp=0x3058c3c sp=0x3058b40 pc=0x1a1334 Mar 29 07:00:21 volumio go-librespot[1295]: net.(*Dialer).DialContext-fm({0xa3da54, 0x313d7d0}, {0x919486, 0x3}, {0x30ac300, 0x16}) Mar 29 07:00:21 volumio go-librespot[1295]: :1 +0x58 fp=0x3058c6c sp=0x3058c3c pc=0x3691a0 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).dial(0xfa9328, {0xa3da54, 0x313d7d0}, {0x919486, 0x3}, {0x30ac300, 0x16}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1278 +0x158 fp=0x3058cac sp=0x3058c6c pc=0x350f60 Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).dialConn(0xfa9328, {0xa3da54, 0x313d7d0}, {{}, 0x0, {0x92ae9f, 0x5}, {0x30ac300, 0x16}, 0x0}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1783 +0x6a4 fp=0x3058f60 sp=0x3058cac pc=0x35393c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).dialConnFor(0xfa9328, 0x3314360) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1618 +0x80 fp=0x3058fc4 sp=0x3058f60 pc=0x35270c Mar 29 07:00:21 volumio go-librespot[1295]: net/http.(*Transport).startDialConnForLocked.func1() Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1600 +0x3c fp=0x3058fec sp=0x3058fc4 pc=0x352594 Mar 29 07:00:21 volumio go-librespot[1295]: runtime.goexit({}) Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/runtime/asm_arm.s:877 +0x4 fp=0x3058fec sp=0x3058fec pc=0xb0874 Mar 29 07:00:21 volumio go-librespot[1295]: created by net/http.(*Transport).startDialConnForLocked in goroutine 136 Mar 29 07:00:21 volumio go-librespot[1295]: /usr/local/go/src/net/http/transport.go:1599 +0x134 Mar 29 07:00:21 volumio go-librespot[1294]: Aborted Mar 29 07:00:24 volumio volumio[995]: info: Initializing connection to go-librespot Websocket Mar 29 07:00:24 volumio volumio[995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 07:00:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 29 07:00:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:00:24 volumio systemd[1]: go-librespot-daemon.service: Consumed 32.756s CPU time. Mar 29 07:00:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:00:24 volumio go-librespot[15569]: go-librespot daemon starting... Mar 29 07:00:24 volumio go-librespot[15570]: time="2026-03-29T07:00:24+02:00" level=info msg="running go-librespot 0.7.1" Mar 29 07:00:24 volumio go-librespot[15570]: time="2026-03-29T07:00:24+02:00" level=debug msg="app state loaded" Mar 29 07:00:24 volumio go-librespot[15570]: time="2026-03-29T07:00:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 29 07:00:27 volumio volumio[995]: info: Initializing connection to go-librespot Websocket Mar 29 07:00:27 volumio go-librespot[15570]: time="2026-03-29T07:00:27+02:00" level=debug msg="new websocket client" Mar 29 07:00:27 volumio volumio[995]: info: Connection to go-librespot Websocket established Mar 29 07:00:30 volumio volumio[995]: info: Getting Spotify volume Mar 29 07:00:30 volumio volumio[995]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 29 07:00:30 volumio volumio[995]: info: CoreCommandRouter::volumioGetState Mar 29 07:00:30 volumio volumio[995]: info: CorePlayQueue::getTrack 0 Mar 29 07:00:30 volumio volumio[995]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 29 07:00:39 volumio go-librespot[15570]: time="2026-03-29T07:00:39+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\": tls: failed to verify certificate: x509: certificate is valid for mediarouter.home, mediarouter1.home, mediarouter2.home, mediarouter3.home, not apresolve.spotify.com" Mar 29 07:00:39 volumio volumio[995]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 07:00:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 07:00:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 07:00:39 volumio volumio[995]: Error: socket hang up Mar 29 07:00:39 volumio volumio[995]: at connResetException (node:internal/errors:720:14) Mar 29 07:00:39 volumio volumio[995]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 29 07:00:39 volumio volumio[995]: at Socket.emit (node:events:526:35) Mar 29 07:00:39 volumio volumio[995]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 29 07:00:39 volumio volumio[995]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 29 07:00:39 volumio volumio[995]: code: 'ECONNRESET', Mar 29 07:00:39 volumio volumio[995]: response: undefined Mar 29 07:00:39 volumio volumio[995]: } Mar 29 07:00:39 volumio volumio[995]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 07:00:41 volumio sudo[15609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-29 06:59' Mar 29 07:00:41 volumio sudo[15609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:00:41 volumio sudo[15609]: pam_unix(sudo:session): session closed for user root Mar 29 07:00:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 29 07:00:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:00:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:00:43 volumio go-librespot[15633]: go-librespot daemon starting... Mar 29 07:00:43 volumio go-librespot[15634]: time="2026-03-29T07:00:43+02:00" level=info msg="running go-librespot 0.7.1" Mar 29 07:00:43 volumio go-librespot[15634]: time="2026-03-29T07:00:43+02:00" level=debug msg="app state loaded" Mar 29 07:00:43 volumio go-librespot[15634]: time="2026-03-29T07:00:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 29 07:00:56 volumio volumio5-onboarding[1278]: time=2026-03-29T07:00:56.680+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 29 07:00:56 volumio volumio-remote-updater[637]: [2026-03-29 07:00:56] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Mar 29 07:00:56 volumio volumio-remote-updater[637]: [2026-03-29 07:00:56] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Mar 29 07:00:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 29 07:00:56 volumio volumio5-onboarding[1278]: time=2026-03-29T07:00:56.686+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 29 07:00:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 29 07:00:56 volumio systemd[1]: volumio.service: Consumed 38min 18.274s CPU time. Mar 29 07:00:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 29 07:00:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 29 07:00:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Mar 29 07:00:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 29 07:00:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 29 07:00:56 volumio systemd[1]: volumio.service: Consumed 38min 18.274s CPU time. Mar 29 07:00:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 29 07:00:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 29 07:00:57 volumio volumio5-onboarding[1278]: time=2026-03-29T07:00:57.694+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 29 07:00:58 volumio go-librespot[15634]: time="2026-03-29T07:00:58+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\": tls: failed to verify certificate: x509: certificate is valid for mediarouter.home, mediarouter1.home, mediarouter2.home, mediarouter3.home, not apresolve.spotify.com" Mar 29 07:00:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 07:00:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 07:00:58 volumio volumio5-onboarding[1278]: time=2026-03-29T07:00:58.697+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 29 07:01:00 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:00 volumio volumio[15686]: info: ----- Volumio3 ---- Mar 29 07:01:00 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:00 volumio volumio[15686]: info: ----- System startup ---- Mar 29 07:01:00 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:01 volumio volumio-remote-updater[637]: [2026-03-29 07:01:01] [connect] Successful connection Mar 29 07:01:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 29 07:01:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:01:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:01:01 volumio go-librespot[15708]: go-librespot daemon starting... Mar 29 07:01:01 volumio go-librespot[15709]: time="2026-03-29T07:01:01+02:00" level=info msg="running go-librespot 0.7.1" Mar 29 07:01:01 volumio go-librespot[15709]: time="2026-03-29T07:01:01+02:00" level=debug msg="app state loaded" Mar 29 07:01:01 volumio go-librespot[15709]: time="2026-03-29T07:01:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 29 07:01:02 volumio volumio[15686]: info: MYVOLUMIO Environment detected Mar 29 07:01:02 volumio volumio[15686]: info: Plugin folders cleanup Mar 29 07:01:02 volumio volumio[15686]: info: Scanning into folder /volumio/app/plugins/ Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category audio_interface Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category miscellanea Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category music_service Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category plugins.json Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category system_controller Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category user_interface Mar 29 07:01:02 volumio volumio[15686]: info: Scanning into folder /data/plugins/ Mar 29 07:01:02 volumio volumio[15686]: info: Scanning category music_service Mar 29 07:01:02 volumio volumio[15686]: info: Plugin folders cleanup completed Mar 29 07:01:02 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:02 volumio volumio[15686]: info: ----- Core plugins startup ---- Mar 29 07:01:02 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:02 volumio volumio[15686]: info: Loading plugins from folder /volumio/app/plugins/ Mar 29 07:01:02 volumio volumio[15686]: info: Adding plugin upnp to MyMusic Plugins Mar 29 07:01:02 volumio volumio[15686]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 29 07:01:02 volumio volumio[15686]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 29 07:01:02 volumio volumio[15686]: info: Loading plugins from folder /data/plugins/ Mar 29 07:01:02 volumio volumio[15686]: info: Loading plugin "system"... Mar 29 07:01:02 volumio volumio[15686]: info: Loading plugin "appearance"... Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "network"... Mar 29 07:01:04 volumio volumio[15686]: info: Refreshing Cached IP Addresses Mar 29 07:01:04 volumio sudo[15724]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 07:01:04 volumio sudo[15724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:04 volumio sudo[15726]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 07:01:04 volumio sudo[15726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "services"... Mar 29 07:01:04 volumio sudo[15724]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "volumio5onboarding"... Mar 29 07:01:04 volumio sudo[15733]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "alsa_controller"... Mar 29 07:01:04 volumio sudo[15733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:04 volumio sudo[15726]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:04 volumio sudo[15733]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:04 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "wizard"... Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "networkfs"... Mar 29 07:01:04 volumio volumio[15686]: info: Starting Udev Watcher for removable devices Mar 29 07:01:04 volumio volumio[15686]: info: Ignoring mount for partition: boot Mar 29 07:01:04 volumio volumio[15686]: info: Ignoring mount for partition: volumio Mar 29 07:01:04 volumio volumio[15686]: info: Ignoring mount for partition: volumio_data Mar 29 07:01:04 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "volumio_command_line_client"... Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "upnp"... Mar 29 07:01:04 volumio volumio[15686]: info: [1774760464784] Starting Upmpd Daemon Mar 29 07:01:04 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "my_music"... Mar 29 07:01:04 volumio volumio[15686]: info: Loading plugin "mpd"... Mar 29 07:01:05 volumio volumio[15686]: info: Loading plugin "upnp_browser"... Mar 29 07:01:08 volumio volumio[15686]: info: Starting UPNP Browser Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "alarm-clock"... Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "airplay_emulation"... Mar 29 07:01:08 volumio volumio[15686]: info: Starting Shairport Sync Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "last_100"... Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "webradio"... Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "i2s_dacs"... Mar 29 07:01:08 volumio volumio[15686]: info: I2S DAC not set, start Auto-detection Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "volumiodiscovery"... Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 29 07:01:08 volumio node[15686]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 29 07:01:08 volumio node[15686]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** For more information see Mar 29 07:01:08 volumio node[15686]: *** WARNING *** For more information see Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 29 07:01:08 volumio node[15686]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 29 07:01:08 volumio node[15686]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 29 07:01:08 volumio volumio[15686]: *** WARNING *** For more information see Mar 29 07:01:08 volumio node[15686]: *** WARNING *** For more information see Mar 29 07:01:08 volumio volumio[15686]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 29 07:01:08 volumio volumio[15686]: info: Discovery: Started advertising with name: Volumio Mar 29 07:01:08 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 29 07:01:08 volumio volumio[15686]: info: Loading plugin "spop"... Mar 29 07:01:09 volumio volumio5-onboarding[1278]: time=2026-03-29T07:01:09.699+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:60184->127.0.0.1:3000: i/o timeout" Mar 29 07:01:10 volumio volumio[15686]: info: Loading plugin "outputs"... Mar 29 07:01:10 volumio volumio[15686]: info: Loading plugin "albumart"... Mar 29 07:01:10 volumio volumio[15686]: info: Plugin example_plugin is not enabled Mar 29 07:01:10 volumio volumio[15686]: info: Loading plugin "inputs"... Mar 29 07:01:10 volumio volumio[15686]: info: Loading plugin "updater_comm"... Mar 29 07:01:11 volumio volumio[15686]: info: Plugin mpdemulation is not enabled Mar 29 07:01:11 volumio volumio[15686]: info: Loading plugin "rest_api"... Mar 29 07:01:11 volumio volumio[15686]: info: Loading plugin "websocket"... Mar 29 07:01:11 volumio volumio[15686]: info: Starting Socket.io Server version 1.7.4 Mar 29 07:01:11 volumio volumio[15686]: info: Loading i18n strings for locale pl Mar 29 07:01:11 volumio volumio[15686]: Updating browse sources language Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::initPlayerControls Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: Express server listening on port 3000 Mar 29 07:01:11 volumio volumio[15686]: [Metrics] WebUI: 12s 19.98ms Mar 29 07:01:11 volumio volumio[15686]: info: CoreStateMachine::resetVolumioState Mar 29 07:01:11 volumio volumio[15686]: info: CoreStateMachine::getcurrentVolume Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::volumioRetrievevolume Mar 29 07:01:11 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:11 volumio volumio[15686]: info: Volumio Network Manager: Network status updated: 1 Mar 29 07:01:11 volumio volumio[15686]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 29 07:01:11 volumio volumio[15686]: wlan0 Interface doesn't support scanning. Mar 29 07:01:11 volumio volumio[15686]: info: Cannot use regular scanning, forcing with ap-force Mar 29 07:01:11 volumio sudo[15780]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 29 07:01:11 volumio sudo[15780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:12 volumio sudo[15780]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:12 volumio volumio[15686]: command failed: No such device (-19) Mar 29 07:01:12 volumio volumio[15686]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Mar 29 07:01:12 volumio volumio[15686]: command failed: No such device (-19) Mar 29 07:01:12 volumio volumio[15763]: Forking 3 albumart workers Mar 29 07:01:12 volumio volumio[15686]: info: VolumeController:: Volume=86 Mute =false Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::pushState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioPushState Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::updateTrackBlock Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrackBlock Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioRetrievevolume Mar 29 07:01:12 volumio volumio[15686]: info: Reloading queue from file Mar 29 07:01:12 volumio volumio[15686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::setRepeat null single undefined Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::pushState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioPushState Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::setRandom null Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::pushState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioPushState Mar 29 07:01:12 volumio volumio[15686]: info: Setting Device type: Raspberry PI Mar 29 07:01:12 volumio volumio[15686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 29 07:01:12 volumio volumio[15686]: info: VolumeController:: Volume=86 Mute =false Mar 29 07:01:12 volumio volumio[15686]: info: CoreStateMachine::pushState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioPushState Mar 29 07:01:12 volumio volumio[15686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 29 07:01:12 volumio volumio[15686]: info: Discovery: adding 8c43c5e2-b35e-4afd-90ff-a2b4f31fed96 Mar 29 07:01:12 volumio volumio[15686]: info: Discovery: Found device Volumio Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioGetState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: Completed loading Core Plugins Mar 29 07:01:12 volumio volumio[15686]: info: Preparing to generate the ALSA configuration file Mar 29 07:01:12 volumio volumio[15686]: info: Discovery: this is already registered, 8c43c5e2-b35e-4afd-90ff-a2b4f31fed96 Mar 29 07:01:12 volumio volumio[15686]: info: Discovery: Found device Volumio Mar 29 07:01:12 volumio volumio[15686]: info: CoreCommandRouter::volumioGetState Mar 29 07:01:12 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:12 volumio volumio[15686]: info: Asound.conf file unchanged, so no further update is needed Mar 29 07:01:12 volumio volumio[15686]: info: Output device has changed, restarting MPD Mar 29 07:01:13 volumio volumio[15686]: info: Output device has changed, restarting Shairport Sync Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:13 volumio sudo[15827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 29 07:01:13 volumio sudo[15827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:13 volumio sudo[15827]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:13 volumio volumio[15686]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 29 07:01:13 volumio volumio[15686]: info: ___________ START PLUGINS ___________ Mar 29 07:01:13 volumio sudo[15829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 29 07:01:13 volumio sudo[15829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:13 volumio volumio[15686]: info: ControllerMpd::onStart: Initializing MPD Mar 29 07:01:13 volumio volumio[15686]: info: Creating MPD Configuration file Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 29 07:01:13 volumio volumio[15686]: info: [1774760473229] CoreMusicLibrary::Adding element Serwery Mediów Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 07:01:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 29 07:01:13 volumio sudo[15837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 29 07:01:13 volumio sudo[15837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:13 volumio volumio[15686]: info: UPNP Browser: Client initialized successfully Mar 29 07:01:13 volumio sudo[15839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 29 07:01:13 volumio sudo[15839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:13 volumio sudo[15839]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:13 volumio sudo[15841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:13 volumio sudo[15841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:13 volumio sudo[15837]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:13 volumio volumio[15686]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 29 07:01:13 volumio volumio[15686]: info: [1774760473602] CoreMusicLibrary::Adding element Last_100 Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 29 07:01:13 volumio volumio[15686]: info: [1774760473611] CoreMusicLibrary::Adding element Webradio Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 29 07:01:13 volumio volumio[15686]: info: Initializing BBC Radios Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:13 volumio volumio[15686]: info: Creating Spotify config file Mar 29 07:01:13 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:13 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 29 07:01:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 29 07:01:13 volumio systemd[1]: mpd.service: Consumed 12.629s CPU time. Mar 29 07:01:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 29 07:01:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 29 07:01:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 29 07:01:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 29 07:01:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 29 07:01:14 volumio volumio-remote-updater[637]: [2026-03-29 07:01:14] [connect] Successful connection Mar 29 07:01:14 volumio sudo[15868]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 29 07:01:14 volumio sudo[15868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 29 07:01:14 volumio sudo[15868]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:14 volumio volumio[15686]: info: Volumio Calling Home Mar 29 07:01:15 volumio volumio[15786]: Starting albumart workers Mar 29 07:01:16 volumio volumio[15785]: Starting albumart workers Mar 29 07:01:16 volumio volumio[15787]: Starting albumart workers Mar 29 07:01:16 volumio sudo[15889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 07:01:16 volumio sudo[15889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:16 volumio volumio[15686]: info: MPD Permissions set Mar 29 07:01:16 volumio sudo[15889]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:16 volumio sudo[15891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 07:01:16 volumio sudo[15891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:16 volumio volumio[15686]: info: MPD Permissions set Mar 29 07:01:16 volumio volumio-remote-updater[637]: [2026-03-29 07:01:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774760474 101 Mar 29 07:01:16 volumio sudo[15891]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:16 volumio volumio[15686]: 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: 2 Mar 29 07:01:16 volumio volumio[15686]: info: Spotify config file written Mar 29 07:01:16 volumio volumio[15686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 29 07:01:16 volumio sudo[15898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 29 07:01:16 volumio sudo[15898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 29 07:01:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 29 07:01:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 29 07:01:16 volumio go-librespot[15906]: go-librespot daemon starting... Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:16 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:17 volumio go-librespot[15907]: time="2026-03-29T07:01:17+02:00" level=info msg="running go-librespot 0.7.1" Mar 29 07:01:17 volumio go-librespot[15907]: time="2026-03-29T07:01:17+02:00" level=debug msg="app state loaded" Mar 29 07:01:17 volumio sudo[15898]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:17 volumio go-librespot[15907]: time="2026-03-29T07:01:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 29 07:01:17 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 07:01:17 volumio volumio[15686]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 07:01:17 volumio volumio[15686]: info: No need to fix Spotify hosts Mar 29 07:01:17 volumio volumio[15686]: info: An error occurred while refreshing Spotify Token Error: self-signed certificate in certificate chain Mar 29 07:01:17 volumio volumio[15686]: info: Starting Shairport Sync Mar 29 07:01:17 volumio volumio[15686]: info: Starting Shairport Sync Mar 29 07:01:17 volumio volumio[15686]: info: Starting Shairport Sync Mar 29 07:01:17 volumio sudo[15921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 29 07:01:17 volumio sudo[15921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:17 volumio sudo[15923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 29 07:01:17 volumio sudo[15923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:17 volumio sudo[15927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 29 07:01:18 volumio sudo[15925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 29 07:01:18 volumio sudo[15925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:18 volumio sudo[15927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 29 07:01:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 29 07:01:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 29 07:01:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 29 07:01:18 volumio systemd[1]: shairport-sync.service: Consumed 10min 49.916s CPU time. Mar 29 07:01:18 volumio volumio[15686]: info: CoreCommandRouter::volumioGetState Mar 29 07:01:18 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 29 07:01:18 volumio sudo[15921]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:18 volumio sudo[15923]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 29 07:01:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 29 07:01:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 29 07:01:18 volumio volumio[15686]: info: Shairport-Sync Started Mar 29 07:01:18 volumio volumio[15686]: Error adding Membership: Error: addMembership EINVAL Mar 29 07:01:18 volumio volumio[15686]: info: Shairport-Sync Started Mar 29 07:01:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 29 07:01:18 volumio sudo[15925]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:18 volumio volumio[15686]: info: Shairport-Sync Started Mar 29 07:01:18 volumio sudo[15927]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:18 volumio volumio[15686]: info: Upmpdcli Daemon Started Mar 29 07:01:20 volumio volumio[15686]: info: go-librespot daemon successfully initialized Mar 29 07:01:21 volumio mpd[15883]: 2026-03-29T07:01:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 29 07:01:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 29 07:01:21 volumio sudo[15841]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:21 volumio sudo[15829]: pam_unix(sudo:session): session closed for user root Mar 29 07:01:21 volumio volumio[15686]: info: Completed starting Core Plugins Mar 29 07:01:21 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:21 volumio volumio[15686]: info: ----- MyVolumio plugins startup ---- Mar 29 07:01:21 volumio volumio[15686]: info: ------------------------------------------- Mar 29 07:01:21 volumio volumio[15686]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 29 07:01:21 volumio volumio[15686]: error: MPD error: The expression evaluated to a falsy value: Mar 29 07:01:21 volumio volumio[15686]: assert.ok(self.idling) Mar 29 07:01:21 volumio volumio[15686]: error: The expression evaluated to a falsy value: Mar 29 07:01:21 volumio volumio[15686]: assert.ok(self.idling) Mar 29 07:01:21 volumio volumio[15686]: info: MPD running with PID15883 Mar 29 07:01:21 volumio volumio[15686]: ,establishing connection Mar 29 07:01:21 volumio volumio[15686]: error: updateQueue error: null Mar 29 07:01:21 volumio volumio[15686]: error: updateQueue error: null Mar 29 07:01:23 volumio volumio[15686]: info: Initializing connection to go-librespot Websocket Mar 29 07:01:23 volumio go-librespot[15907]: time="2026-03-29T07:01:23+02:00" level=debug msg="new websocket client" Mar 29 07:01:23 volumio volumio[15686]: info: Connection to go-librespot Websocket established Mar 29 07:01:26 volumio volumio[15686]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 29 07:01:26 volumio volumio[15686]: info: Getting Spotify volume Mar 29 07:01:26 volumio volumio[15686]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 29 07:01:26 volumio volumio[15686]: info: CoreCommandRouter::volumioGetState Mar 29 07:01:26 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:26 volumio volumio[15686]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 29 07:01:26 volumio volumio[15686]: SPOTIFY: SPOTIFY VOLUME undefined Mar 29 07:01:26 volumio volumio[15686]: SPOTIFY: VOLUMIO VOLUME 86 Mar 29 07:01:26 volumio volumio[15686]: info: Aligning Spotify Volume to Volumio Volume Mar 29 07:01:26 volumio volumio[15686]: info: CoreCommandRouter::volumioGetState Mar 29 07:01:26 volumio volumio[15686]: info: CorePlayQueue::getTrack 0 Mar 29 07:01:26 volumio volumio[15686]: info: Setting Spotify Volume from Volumio: 86 Mar 29 07:01:28 volumio volumio[15686]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Mar 29 07:01:28 volumio volumio[15686]: info: Sending Spotify command with payload to local API: /player/volume Mar 29 07:01:30 volumio volumio[15686]: info: Volumio called home Mar 29 07:01:32 volumio go-librespot[15907]: time="2026-03-29T07:01:32+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\": tls: failed to verify certificate: x509: certificate is valid for mediarouter.home, mediarouter1.home, mediarouter2.home, mediarouter3.home, not apresolve.spotify.com" Mar 29 07:01:32 volumio volumio[15686]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Mar 29 07:01:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 07:01:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 07:01:32 volumio volumio[15686]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 07:01:32 volumio volumio[15686]: Error: socket hang up Mar 29 07:01:32 volumio volumio[15686]: at connResetException (node:internal/errors:720:14) Mar 29 07:01:32 volumio volumio[15686]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 29 07:01:32 volumio volumio[15686]: at Socket.emit (node:events:526:35) Mar 29 07:01:32 volumio volumio[15686]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 29 07:01:32 volumio volumio[15686]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 29 07:01:32 volumio volumio[15686]: code: 'ECONNRESET', Mar 29 07:01:32 volumio volumio[15686]: response: undefined Mar 29 07:01:32 volumio volumio[15686]: } Mar 29 07:01:32 volumio volumio[15686]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 07:01:33 volumio sudo[16001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-29 07:00' Mar 29 07:01:33 volumio sudo[16001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"