Jul 11 15:54:05 volumiopi4 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 11 15:54:05 volumiopi4 dbus-daemon[698]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.72' (uid=0 pid=4889 comm="timedatectl show --property=NTPSynchronized --valu") Jul 11 15:54:05 volumiopi4 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 11 15:54:06 volumiopi4 dbus-daemon[698]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 11 15:54:06 volumiopi4 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 11 15:54:06 volumiopi4 setdatetime-helper.sh[4888]: Time is already synchronized. Jul 11 15:54:06 volumiopi4 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 11 15:54:06 volumiopi4 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 11 15:54:13 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:13+02:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Jul 11 15:54:14 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:14+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jul 11 15:54:15 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:15+02:00" level=debug msg="completed keyexchange" Jul 11 15:54:15 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:15+02:00" level=debug msg="completed challenge" Jul 11 15:54:19 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:19+02:00" level=error msg="did not receive last pong ack from accesspoint, 841s passed" Jul 11 15:54:19 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:19+02:00" level=trace msg="sent dealer ping" Jul 11 15:54:19 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:19+02:00" level=trace msg="received dealer pong" Jul 11 15:54:36 volumiopi4 systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 11 15:54:49 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:49+02:00" level=trace msg="sent dealer ping" Jul 11 15:54:49 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:49+02:00" level=trace msg="received dealer pong" Jul 11 15:54:57 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:57+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jul 11 15:54:57 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:57+02:00" level=debug msg="completed keyexchange" Jul 11 15:54:57 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:57+02:00" level=debug msg="completed challenge" Jul 11 15:54:58 volumiopi4 go-librespot[1548]: time="2025-07-11T15:54:58+02:00" level=error msg="failed reconnecting accesspoint" error="failed authenticating: accesspoint login failed: BadCredentials " Jul 11 15:54:58 volumiopi4 go-librespot[1548]: fatal error: sync: Unlock of unlocked RWMutex Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 69 gp=0x22ec008 m=3 mp=0x2048b08 [running]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.fatal({0x71be82, 0x20}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/panic.go:1042 +0x4c fp=0x220fee0 sp=0x220fecc pc=0x596e8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: sync.fatal({0x71be82, 0x20}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/panic.go:1007 +0x24 fp=0x220feec sp=0x220fee0 pc=0x8fdec Jul 11 15:54:58 volumiopi4 go-librespot[1548]: sync.(*RWMutex).Unlock(0x21957e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/sync/rwmutex.go:208 +0x50 fp=0x220ff04 sp=0x220feec pc=0xa0da0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).recvLoop(0x2195768) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:329 +0x4bc fp=0x220ffe4 sp=0x220ff04 pc=0x4855dc Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:260 +0x28 fp=0x220ffec sp=0x220ffe4 pc=0x4850f4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x220ffec sp=0x220ffec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 50 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:260 +0x98 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 1 gp=0x2002128 m=nil [select, 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2057cfc sp=0x2057ce8 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x2057dfc, 0x220fdc8, 0x0, 0x0, 0x2, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2057d9c sp=0x2057cfc pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x2028300, 0x2057e88) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/zeroconf/zeroconf.go:270 +0x228 fp=0x2057e40 sp=0x2057d9c pc=0x55dd34 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).withAppPlayer(0x2079a80, {0x7d7634, 0xbf6000}, 0x200f260) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:316 +0x514 fp=0x2057ec8 sp=0x2057e40 pc=0x5f2dcc Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).withCredentials(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:190 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).SpotifyToken(0x2079a80, {0x7d7634, 0xbf6000}, {0x207e700, 0x19}, {0x2222000, 0x12f}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:182 +0xd8 fp=0x2057ef8 sp=0x2057ec8 pc=0x5f22c0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.main() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:618 +0x61c fp=0x2057fa8 sp=0x2057ef8 pc=0x5f5a58 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.main() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:271 +0x2fc fp=0x2057fec sp=0x2057fa8 pc=0x5ca38 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2057fec sp=0x2057fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 2 gp=0x2002c68 m=nil [force gc (idle), 3 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736864, 0xbca928, 0x11, 0xa, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2044fd4 sp=0x2044fc0 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goparkunlock(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:408 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.forcegchelper() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:326 +0xe4 fp=0x2044fec sp=0x2044fd4 pc=0x5ce04 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2044fec sp=0x2044fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.init.5 in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:314 +0x1c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 3 gp=0x2002d88 m=nil [GC sweep wait]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736864, 0xbcaee0, 0xc, 0x9, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x20457c4 sp=0x20457b0 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goparkunlock(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:408 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.bgsweep(0x2074000) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgcsweep.go:318 +0x11c fp=0x20457e4 sp=0x20457c4 pc=0x45750 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcenable.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:203 +0x28 fp=0x20457ec sp=0x20457e4 pc=0x35870 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20457ec sp=0x20457ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcenable in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:203 +0x74 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 4 gp=0x2002ea8 m=nil [GC scavenge wait]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736864, 0xbcb508, 0xd, 0xa, 0x2) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2045fb4 sp=0x2045fa0 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goparkunlock(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:408 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.(*scavengerState).park(0xbcb508) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x2045fc8 sp=0x2045fb4 pc=0x42a70 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.bgscavenge(0x2074000) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x2045fe4 sp=0x2045fc8 pc=0x431a8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcenable.gowrap2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:204 +0x28 fp=0x2045fec sp=0x2045fe4 pc=0x3581c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2045fec sp=0x2045fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcenable in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:204 +0xbc Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 5 gp=0x2002fc8 m=nil [finalizer wait]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736710, 0xbf609c, 0x10, 0xa, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x204678c sp=0x2046778 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.runfinq() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mfinal.go:194 +0x110 fp=0x20467ec sp=0x204678c pc=0x3465c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20467ec sp=0x20467ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.createfing in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mfinal.go:164 +0x5c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 7 gp=0x2084488 m=nil [IO wait, 28 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7ef18, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x215dd28 sp=0x215dd14 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7ef08, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x215dd40 sp=0x215dd28 pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7ef08, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x215dd54 sp=0x215dd40 pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x21ccfb8, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x215dd68 sp=0x215dd54 pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).Accept(0x21ccfa0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:611 +0x294 fp=0x215ddb0 sp=0x215dd68 pc=0x10eb44 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*netFD).accept(0x21ccfa0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/fd_unix.go:172 +0x20 fp=0x215de18 sp=0x215ddb0 pc=0x17e32c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPListener).accept(0x2026570) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x215de30 sp=0x215de18 pc=0x19642c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPListener).Accept(0x2026570) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/tcpsock.go:327 +0x30 fp=0x215de4c sp=0x215de30 pc=0x195498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*onceCloseListener).Accept(0x20aa7a0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: :1 +0x34 fp=0x215de64 sp=0x215de4c pc=0x362680 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*Server).Serve(0x20a8468, {0x7d6e18, 0x2026570}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:3255 +0x314 fp=0x215defc sp=0x215de64 pc=0x340d3c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.Serve(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2794 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*ConcreteApiServer).serve(0x20cc180) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/api_server.go:610 +0x974 fp=0x215dfe4 sp=0x215defc pc=0x5e8bc0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.NewApiServer.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/api_server.go:289 +0x28 fp=0x215dfec sp=0x215dfe4 pc=0x5e7a90 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x215dfec sp=0x215dfec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by main.NewApiServer in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/api_server.go:289 +0x310 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 20 gp=0x22267e8 m=nil [GC worker (idle)]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736720, 0x20a1de8, 0x1a, 0xa, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2046f90 sp=0x2046f7c pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcBgMarkWorker() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x2046fec sp=0x2046f90 pc=0x38498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2046fec sp=0x2046fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcBgMarkStartWorkers in goroutine 19 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 34 gp=0x2104248 m=nil [GC worker (idle), 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736720, 0x20a1dd0, 0x1a, 0xa, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2040790 sp=0x204077c pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcBgMarkWorker() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x20407ec sp=0x2040790 pc=0x38498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20407ec sp=0x20407ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcBgMarkStartWorkers in goroutine 19 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 21 gp=0x20847e8 m=nil [GC worker (idle), 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736720, 0x20a1e00, 0x1a, 0xa, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2044790 sp=0x204477c pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcBgMarkWorker() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x20447ec sp=0x2044790 pc=0x38498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20447ec sp=0x20447ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcBgMarkStartWorkers in goroutine 19 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 13 gp=0x2226908 m=nil [GC worker (idle), 11 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736720, 0x2134df8, 0x1a, 0xa, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2047f90 sp=0x2047f7c pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gcBgMarkWorker() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x2047fec sp=0x2047f90 pc=0x38498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2047fec sp=0x2047fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by runtime.gcBgMarkStartWorkers in goroutine 19 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 14 gp=0x2226008 m=nil [IO wait]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7ed38, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x215ee84 sp=0x215ee70 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7ed28, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x215ee9c sp=0x215ee84 pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7ed28, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x215eeb0 sp=0x215ee9c pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x2228108, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x215eec4 sp=0x215eeb0 pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).RawRead(0x22280f0, 0x22d24e0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:708 +0x164 fp=0x215eef0 sp=0x215eec4 pc=0x10f748 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*rawConn).Read(0x2110240, 0x22d24e0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x215ef10 sp=0x215eef0 pc=0x190854 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x211c1d0, 0x22d24b0, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/rawconn_msg.go:27 +0x154 fp=0x215ef40 sp=0x215ef10 pc=0x4fe72c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/socket.go:247 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x2246038, {0x23b2000, 0x10000, 0x10000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/ipv4/payload_cmsg.go:31 +0x44c fp=0x215ef9c sp=0x215ef40 pc=0x502714 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/grandcat/zeroconf.(*Server).recv4(0x222e480, 0x2246030) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xec fp=0x215efe0 sp=0x215ef9c pc=0x558fa4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x215efec sp=0x215efe0 pc=0x558c5c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x215efec sp=0x215efec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 22 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 15 gp=0x2226128 m=nil [IO wait, 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7ec98, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x216de5c sp=0x216de48 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7ec88, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x216de74 sp=0x216de5c pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7ec88, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x216de88 sp=0x216de74 pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x2228158, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x216de9c sp=0x216de88 pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).RawRead(0x2228140, 0x2156390) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:708 +0x164 fp=0x216dec8 sp=0x216de9c pc=0x10f748 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*rawConn).Read(0x2110268, 0x2156390) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x216dee8 sp=0x216dec8 pc=0x190854 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x211c1e0, 0x2156360, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/rawconn_msg.go:27 +0x154 fp=0x216df18 sp=0x216dee8 pc=0x4fe72c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/socket.go:247 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x2246068, {0x216e000, 0x10000, 0x10000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/golang.org/x/net@v0.26.0/ipv6/payload_cmsg.go:31 +0x2ec fp=0x216df9c sp=0x216df18 pc=0x50609c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/grandcat/zeroconf.(*Server).recv6(0x222e480, 0x2246060) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xec fp=0x216dfe0 sp=0x216df9c pc=0x559198 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x216dfec sp=0x216dfe0 pc=0x558c00 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x216dfec sp=0x216dfec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 22 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 49 gp=0x2085448 m=nil [select, 28 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2041674 sp=0x2041660 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x2041774, 0x204173c, 0x0, 0x0, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2041714 sp=0x2041674 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/player.(*Player).manageLoop(0x24fe3c0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/player/player.go:181 +0x1fc fp=0x20417e4 sp=0x2041714 pc=0x4cbbd8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/player.NewPlayer.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/player/player.go:163 +0x28 fp=0x20417ec sp=0x20417e4 pc=0x4cb7b8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20417ec sp=0x20417ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/player.NewPlayer in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/player/player.go:163 +0x1c8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 50 gp=0x2390a28 m=nil [select, 16 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x220d854 sp=0x220d840 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x220de10, 0x220da34, 0x0, 0x0, 0x8, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x220d8f4 sp=0x220d854 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*AppPlayer).Run(0x2228190, {0x7d7634, 0xbf6000}, 0x2075b00) Jul 11 15:54:58 volumiopi4 volumio[1238]: info: Connection to go-librespot Websocket closed Jul 11 15:54:58 volumiopi4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/player.go:570 +0x370 fp=0x220dfd8 sp=0x220d8f4 pc=0x5faf20 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).withAppPlayer.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:254 +0x40 fp=0x220dfec sp=0x220dfd8 pc=0x5f3a44 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x220dfec sp=0x220dfec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by main.(*App).withAppPlayer in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:254 +0x398 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 51 gp=0x2390b48 m=nil [chan receive, 28 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x7366f4, 0x20d8070, 0xe, 0x7, 0x2) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x24aff48 sp=0x24aff34 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.chanrecv(0x20d8040, 0x24affd0, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/chan.go:583 +0x4b0 fp=0x24aff84 sp=0x24aff48 pc=0x1ff80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.chanrecv2(0x20d8040, 0x24affd0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/chan.go:447 +0x20 fp=0x24aff98 sp=0x24aff84 pc=0x1fac4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).withAppPlayer.func1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:264 +0x68 fp=0x24affec sp=0x24aff98 pc=0x5f3964 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x24affec sp=0x24affec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by main.(*App).withAppPlayer in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:261 +0x424 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 52 gp=0x2390c68 m=nil [chan receive, 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x7366f4, 0x2074230, 0xe, 0x7, 0x2) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x24b0738 sp=0x24b0724 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.chanrecv(0x2074200, 0x24b07e0, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/chan.go:583 +0x4b0 fp=0x24b0774 sp=0x24b0738 pc=0x1ff80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.chanrecv2(0x2074200, 0x24b07e0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/chan.go:447 +0x20 fp=0x24b0788 sp=0x24b0774 pc=0x1fac4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*App).withAppPlayer.func2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:280 +0x6c fp=0x24b07ec sp=0x24b0788 pc=0x5f352c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x24b07ec sp=0x24b07ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by main.(*App).withAppPlayer in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/main.go:277 +0x4c4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 143 gp=0x2390ea8 m=nil [IO wait]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7ea18, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2163940 sp=0x216392c pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7ea08, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x2163958 sp=0x2163940 pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7ea08, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x216396c sp=0x2163958 pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x21cc338, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2163980 sp=0x216396c pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).Read(0x21cc320, {0x2015000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x21639c8 sp=0x2163980 pc=0x10b4c4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*netFD).Read(0x21cc320, {0x2015000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x21639f4 sp=0x21639c8 pc=0x17c438 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*conn).Read(0x241a2d8, {0x2015000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x2163a20 sp=0x21639f4 pc=0x18c618 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPConn).Read(0x241a2d8, {0x2015000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: :1 +0x44 fp=0x2163a40 sp=0x2163a20 pc=0x19f86c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: crypto/tls.(*atLeastReader).Read(0x200e480, {0x2015000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/crypto/tls/conn.go:806 +0x78 fp=0x2163a6c sp=0x2163a40 pc=0x27c1ac Jul 11 15:54:58 volumiopi4 go-librespot[1548]: bytes.(*Buffer).ReadFrom(0x20b060c, {0x7d4554, 0x200e480}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/bytes/buffer.go:211 +0xa4 fp=0x2163aa8 sp=0x2163a6c pc=0x139b90 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: crypto/tls.(*Conn).readFromUntil(0x20b0488, {0x7d373c, 0x241a2d8}, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/crypto/tls/conn.go:828 +0xd4 fp=0x2163ad0 sp=0x2163aa8 pc=0x27c408 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: crypto/tls.(*Conn).readRecordOrCCS(0x20b0488, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/crypto/tls/conn.go:626 +0x134 fp=0x2163c34 sp=0x2163ad0 pc=0x279b08 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: crypto/tls.(*Conn).readRecord(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/crypto/tls/conn.go:588 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: crypto/tls.(*Conn).Read(0x20b0488, {0x20fa000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/crypto/tls/conn.go:1370 +0x15c fp=0x2163c64 sp=0x2163c34 pc=0x27f978 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*readWriteCloserBody).Read(0x200e8c0, {0x20fa000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 systemd[1]: go-librespot-daemon.service: Consumed 1.019s CPU time. Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/transport.go:2429 +0xec fp=0x2163c84 sp=0x2163c64 pc=0x35762c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: bufio.(*Reader).fill(0x20db9b0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/bufio/bufio.go:110 +0x10c fp=0x2163ca8 sp=0x2163c84 pc=0x2bd8e0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: bufio.(*Reader).ReadByte(0x20db9b0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/bufio/bufio.go:269 +0x28 fp=0x2163cb4 sp=0x2163ca8 pc=0x2be164 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.readFrameHeader(0x20db9b0, {0x212c678, 0x8, 0x8}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2163cf4 sp=0x2163cb4 pc=0x470950 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x212c648, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2163db4 sp=0x2163cf4 pc=0x4735b4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).readLoop(0x212c648, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2163e78 sp=0x2163db4 pc=0x47309c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).reader(0x212c648, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x2163f04 sp=0x2163e78 pc=0x4742b0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).Reader(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).Read(0x212c648, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x2163f2c sp=0x2163f04 pc=0x472980 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/dealer.(*Dealer).recvLoop(0x2195978) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:188 +0x58 fp=0x2163fe4 sp=0x2163f2c pc=0x4e8b14 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:295 +0x28 fp=0x2163fec sp=0x2163fe4 pc=0x4e9768 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2163fec sp=0x2163fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).reconnect in goroutine 71 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:295 +0xf4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 142 gp=0x2390fc8 m=nil [select]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2042ea8 sp=0x2042e94 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x2042fa4, 0x2042f6c, 0x0, 0x0, 0x5, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2042f48 sp=0x2042ea8 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x212c648) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x2042fe4 sp=0x2042f48 pc=0x46d7fc Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.newConn.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x2042fec sp=0x2042fe4 pc=0x46d3f0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2042fec sp=0x2042fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by nhooyr.io/websocket.newConn in goroutine 71 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 56 gp=0x23910e8 m=nil [IO wait, 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7edd8, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x24b0de8 sp=0x24b0dd4 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7edc8, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x24b0e00 sp=0x24b0de8 pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7edc8, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x24b0e14 sp=0x24b0e00 pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x22280b8, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x24b0e28 sp=0x24b0e14 pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).Accept(0x22280a0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:611 +0x294 fp=0x24b0e70 sp=0x24b0e28 pc=0x10eb44 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*netFD).accept(0x22280a0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/fd_unix.go:172 +0x20 fp=0x24b0ed8 sp=0x24b0e70 pc=0x17e32c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPListener).accept(0x222a0d8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x24b0ef0 sp=0x24b0ed8 pc=0x19642c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPListener).Accept(0x222a0d8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/tcpsock.go:327 +0x30 fp=0x24b0f0c sp=0x24b0ef0 pc=0x195498 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*onceCloseListener).Accept(0x235f440) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: :1 +0x34 fp=0x24b0f24 sp=0x24b0f0c pc=0x362680 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*Server).Serve(0x2122148, {0x7d6e18, 0x222a0d8}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:3255 +0x314 fp=0x24b0fbc sp=0x24b0f24 pc=0x340d3c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.Serve(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2794 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/zeroconf/zeroconf.go:267 +0x8c fp=0x24b0fec sp=0x24b0fbc pc=0x55de30 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x24b0fec sp=0x24b0fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/zeroconf/zeroconf.go:267 +0x160 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 70 gp=0x22ec248 m=nil [select]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x215ceb8 sp=0x215cea4 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x215cfd4, 0x215cf7c, 0x0, 0x0, 0x2, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x215cf58 sp=0x215ceb8 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).pongAckTicker(0x2195768) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:355 +0x8c fp=0x215cfe4 sp=0x215cf58 pc=0x4859a8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:264 +0x28 fp=0x215cfec sp=0x215cfe4 pc=0x4850a0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x215cfec sp=0x215cfec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 50 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/ap/ap.go:264 +0x15c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 72 gp=0x22ec5a8 m=nil [select]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2056e98 sp=0x2056e84 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x2056fd4, 0x2056f60, 0x0, 0x0, 0x2, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2056f38 sp=0x2056e98 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/dealer.(*Dealer).pingTicker(0x2195978) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:138 +0x8c fp=0x2056fe4 sp=0x2056f38 pc=0x4e868c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: github.com/devgianlu/go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1.gowrap2() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:129 +0x28 fp=0x2056fec sp=0x2056fe4 pc=0x4ea594 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2056fec sp=0x2056fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by github.com/devgianlu/go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1 in goroutine 50 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/dealer/dealer.go:129 +0x15c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 57 gp=0x2104488 m=nil [IO wait, 30 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736854, 0xb4f7e8d8, 0x2, 0x2, 0x5) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x216187c sp=0x2161868 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.netpollblock(0xb4f7e8c8, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x2161894 sp=0x216187c pc=0x547d4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.runtime_pollWait(0xb4f7e8c8, 0x72) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x21618a8 sp=0x2161894 pc=0x8f388 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).wait(0x21cc108, 0x72, 0x0) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x21618bc sp=0x21618a8 pc=0x10a2d8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*pollDesc).waitRead(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: internal/poll.(*FD).Read(0x21cc0f0, {0x2012000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2161904 sp=0x21618bc pc=0x10b4c4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*netFD).Read(0x21cc0f0, {0x2012000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x2161930 sp=0x2161904 pc=0x17c438 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*conn).Read(0x2394000, {0x2012000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x216195c sp=0x2161930 pc=0x18c618 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net.(*TCPConn).Read(0x2394000, {0x2012000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: :1 +0x44 fp=0x216197c sp=0x216195c pc=0x19f86c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: io.(*multiReader).Read(0x24e6030, {0x2012000, 0x1000, 0x1000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x21619a8 sp=0x216197c pc=0x1054e8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: bufio.(*Reader).fill(0x24ea090) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/bufio/bufio.go:110 +0x10c fp=0x21619cc sp=0x21619a8 pc=0x2bd8e0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: bufio.(*Reader).ReadByte(0x24ea090) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/bufio/bufio.go:269 +0x28 fp=0x21619d8 sp=0x21619cc pc=0x2be164 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.readFrameHeader(0x24ea090, {0x21fc3f8, 0x8, 0x8}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2161a18 sp=0x21619d8 pc=0x470950 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x21fc3c8, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2161ad8 sp=0x2161a18 pc=0x4735b4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).readLoop(0x21fc3c8, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2161b9c sp=0x2161ad8 pc=0x47309c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).reader(0x21fc3c8, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x2161c28 sp=0x2161b9c pc=0x4742b0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).Reader(...) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).Read(0x21fc3c8, {0x7d7614, 0xbf6000}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x2161c50 sp=0x2161c28 pc=0x472980 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*ConcreteApiServer).serve.func17({0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/cmd/daemon/api_server.go:580 +0x3c0 fp=0x2161ccc sp=0x2161c50 pc=0x5e9490 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.HandlerFunc.ServeHTTP(0x20982f8, {0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x2161cdc sp=0x2161ccc pc=0x33d320 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*ServeMux).ServeHTTP(0x20b4180, {0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2683 +0x208 fp=0x2161d18 sp=0x2161cdc pc=0x33f180 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x1f8 fp=0x2161d40 sp=0x2161d18 pc=0x5e8e90 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.HandlerFunc.ServeHTTP(0x20c8260, {0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x2161d50 sp=0x2161d40 pc=0x33d320 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.serverHandler.ServeHTTP({0x20a8468}, {0x7d6f4c, 0x2122288}, 0x21221e8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:3137 +0xe0 fp=0x2161d6c sp=0x2161d50 pc=0x340910 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*conn).serve(0x211e360, {0x7d7654, 0x20a2438}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:2039 +0x61c fp=0x2161fdc sp=0x2161d6c pc=0x33bb60 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: net/http.(*Server).Serve.gowrap3() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:3285 +0x38 fp=0x2161fec sp=0x2161fdc pc=0x3411b4 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2161fec sp=0x2161fec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by net/http.(*Server).Serve in goroutine 7 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/net/http/server.go:3285 +0x468 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: goroutine 59 gp=0x21046c8 m=nil [select, 28 minutes]: Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.gopark(0x736898, 0x0, 0x9, 0x3, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x20476a8 sp=0x2047694 pc=0x5cfc8 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.selectgo(0x20477a4, 0x204776c, 0x0, 0x0, 0x5, 0x1) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2047748 sp=0x20476a8 pc=0x70d80 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x21fc3c8) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x20477e4 sp=0x2047748 pc=0x46d7fc Jul 11 15:54:58 volumiopi4 go-librespot[1548]: nhooyr.io/websocket.newConn.gowrap1() Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x20477ec sp=0x20477e4 pc=0x46d3f0 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: runtime.goexit({}) Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20477ec sp=0x20477ec pc=0x93c4c Jul 11 15:54:58 volumiopi4 go-librespot[1548]: created by nhooyr.io/websocket.newConn in goroutine 57 Jul 11 15:54:58 volumiopi4 go-librespot[1548]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Jul 11 15:54:58 volumiopi4 go-librespot[1542]: Aborted Jul 11 15:55:01 volumiopi4 volumio[1238]: info: Initializing connection to go-librespot Websocket Jul 11 15:55:01 volumiopi4 volumio[1238]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 15:55:01 volumiopi4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 11 15:55:01 volumiopi4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 11 15:55:01 volumiopi4 systemd[1]: go-librespot-daemon.service: Consumed 1.019s CPU time. Jul 11 15:55:01 volumiopi4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 11 15:55:01 volumiopi4 go-librespot[4965]: go-librespot daemon starting... Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=info msg="running go-librespot 0.2.0" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=debug msg="app state loaded" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jul 11 15:55:01 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:01+02:00" level=info msg="zeroconf server listening on port 36335" Jul 11 15:55:02 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:02+02:00" level=debug msg="obtained new client token: AADI1B4UAL3M5LEwDyis4Bsg9Q8fcT2S1EGpjpAjYsB+C/uFS4vF1Gu3RMLjDUasLxx1sZSWr7s0loH2cHu1bgZRgQEfIhsCdu5r97OTyGyE/R3w9poLQi/+10xYGuTwOzJKLP7Qg7hNjb4cxOYCfLF6Pd04ZwY+cCh0bbRxaH8DI6wQXJ9EgmAarvtCNONabKHIV1Uzyac94NKLMq/aL/f6Ga5ccjn0WV1Q+t1QvbbivtqKPwiyUzrvKro=" Jul 11 15:55:02 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jul 11 15:55:02 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:02+02:00" level=debug msg="completed keyexchange" Jul 11 15:55:02 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:02+02:00" level=debug msg="completed challenge" Jul 11 15:55:03 volumiopi4 go-librespot[4966]: time="2025-07-11T15:55:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jul 11 15:55:03 volumiopi4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 15:55:03 volumiopi4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 15:55:04 volumiopi4 volumio[1238]: info: Initializing connection to go-librespot Websocket Jul 11 15:55:04 volumiopi4 volumio[1238]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 15:55:06 volumiopi4 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 11 15:55:06 volumiopi4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 11 15:55:06 volumiopi4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 11 15:55:06 volumiopi4 go-librespot[4988]: go-librespot daemon starting... Jul 11 15:55:06 volumiopi4 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=info msg="running go-librespot 0.2.0" Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=debug msg="app state loaded" Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 11 15:55:06 volumiopi4 dbus-daemon[698]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.74' (uid=0 pid=4996 comm="timedatectl show --property=NTPSynchronized --valu") Jul 11 15:55:06 volumiopi4 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 11 15:55:06 volumiopi4 dbus-daemon[698]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 11 15:55:06 volumiopi4 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 11 15:55:06 volumiopi4 setdatetime-helper.sh[4990]: Time is already synchronized. Jul 11 15:55:06 volumiopi4 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 11 15:55:06 volumiopi4 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jul 11 15:55:06 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:06+02:00" level=info msg="zeroconf server listening on port 41997" Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=debug msg="obtained new client token: AABkq0yIWWUHocKQUKqiDxYSFjcSHgzXOq1G4pxty0aZhnwBLeFmEf9WThrutPcCU9QiN46sokRfj6p/d6MRr+Fw+6X1LEvmAT8KsA40Zu6QToe5cUtJ0r0PeK5TRQhVt1WbTbDVps2yspIVK6kZrW1vIjNLhhBKF7HYXTMEFzxqf49nJkiX02NLvjiokboawUhKF4LtPpyL4Ou9di2QMWwRgCcrzdE30GG/n6p289TCea7UavxFPf1f" Jul 11 15:55:07 volumiopi4 volumio[1238]: info: Initializing connection to go-librespot Websocket Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=debug msg="new websocket client" Jul 11 15:55:07 volumiopi4 volumio[1238]: info: Connection to go-librespot Websocket established Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=debug msg="completed keyexchange" Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=debug msg="completed challenge" Jul 11 15:55:07 volumiopi4 go-librespot[4989]: time="2025-07-11T15:55:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jul 11 15:55:07 volumiopi4 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 11 15:55:07 volumiopi4 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 11 15:55:07 volumiopi4 volumio[1238]: info: Connection to go-librespot Websocket closed Jul 11 15:55:10 volumiopi4 volumio[1238]: info: Getting Spotify volume Jul 11 15:55:10 volumiopi4 volumio[1238]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 15:55:10 volumiopi4 volumio[1238]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 11 15:55:10 volumiopi4 volumio[1238]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jul 11 15:55:10 volumiopi4 volumio[1238]: errno: -111, Jul 11 15:55:10 volumiopi4 volumio[1238]: code: 'ECONNREFUSED', Jul 11 15:55:10 volumiopi4 volumio[1238]: syscall: 'connect', Jul 11 15:55:10 volumiopi4 volumio[1238]: address: '127.0.0.1', Jul 11 15:55:10 volumiopi4 volumio[1238]: port: 9879, Jul 11 15:55:10 volumiopi4 volumio[1238]: response: undefined Jul 11 15:55:10 volumiopi4 volumio[1238]: } Jul 11 15:55:10 volumiopi4 volumio[1238]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 15:55:10 volumiopi4 sudo[5015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-11 15:54' Jul 11 15:55:10 volumiopi4 sudo[5015]: 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="4f980d5cf693b4272997a2fa2da8bb8036ddf1ab" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jul 5 02:50:33 UTC 2025" VOLUMIO_VERSION="4.015" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d42ab79cc13d24482826e04fda2e8350"