-- Logs begin at Thu 2019-02-14 15:41:59 IST, end at Tue 2025-01-14 02:13:10 IST. -- Jan 14 02:12:00 volumio-sk go-librespot[3822]: time="2025-01-14T02:12:00+05:30" level=error msg="failed receiving dealer message" error="failed to get reader: WebSocket closed: sent close frame: status = StatusServiceRestart and reason = \"\"" Jan 14 02:12:00 volumio-sk wpa_supplicant[912]: wlan0: Failed to initiate sched scan Jan 14 02:12:01 volumio-sk volumio[1016]: info: Selecting previously unselected package python3-setuptools. Jan 14 02:12:01 volumio-sk volumio[1016]: info: Preparing to unpack .../48-python3-setuptools_40.8.0-1_all.deb ... Jan 14 02:12:01 volumio-sk volumio[1016]: info: Unpacking python3-setuptools (40.8.0-1) ... Jan 14 02:12:04 volumio-sk nmbd[768]: [2025/01/14 02:12:04.680990, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) Jan 14 02:12:04 volumio-sk nmbd[768]: reload_interfaces: No subnets to listen to. Waiting.. Jan 14 02:12:05 volumio-sk wpa_supplicant[912]: wlan0: Failed to initiate sched scan Jan 14 02:12:05 volumio-sk volumio[1016]: info: Selecting previously unselected package python3-wheel. Jan 14 02:12:05 volumio-sk volumio[1016]: info: Preparing to unpack .../49-python3-wheel_0.32.3-2_all.deb ... Jan 14 02:12:05 volumio-sk volumio[1016]: info: Unpacking python3-wheel (0.32.3-2) ... Jan 14 02:12:06 volumio-sk volumio[1016]: info: Selecting previously unselected package python3-xdg. Jan 14 02:12:06 volumio-sk volumio[1016]: info: Preparing to unpack .../50-python3-xdg_0.25-5_all.deb ... Jan 14 02:12:06 volumio-sk volumio[1016]: info: Unpacking python3-xdg (0.25-5) ... Jan 14 02:12:07 volumio-sk volumio[1016]: info: Setting up python3-entrypoints (0.3-1) ... Jan 14 02:12:08 volumio-sk volumio[1016]: info: Setting up dh-python (3.20190308) ... Jan 14 02:12:09 volumio-sk volumio[1016]: info: Setting up python3-attr (18.2.0-1) ... Jan 14 02:12:10 volumio-sk volumio[1016]: info: Setting up python3-dbus (1.2.8-3) ... Jan 14 02:12:11 volumio-sk volumio[1016]: info: Setting up python3-setuptools (40.8.0-1) ... Jan 14 02:12:11 volumio-sk wpa_supplicant[912]: wlan0: Failed to initiate sched scan Jan 14 02:12:12 volumio-sk volumio[1016]: info: Setting up libpython3.7:armhf (3.7.3-2+deb10u7) ... Jan 14 02:12:12 volumio-sk volumio[1016]: info: Setting up libalgorithm-diff-perl (1.19.03-2) ... Jan 14 02:12:12 volumio-sk volumio[1016]: info: Setting up python3-xdg (0.25-5) ... Jan 14 02:12:13 volumio-sk volumio[1016]: info: Setting up bzip2 (1.0.6-9.2~deb10u2) ... Jan 14 02:12:13 volumio-sk volumio[1016]: info: Setting up python3-wheel (0.32.3-2) ... Jan 14 02:12:14 volumio-sk volumio[1016]: info: Setting up python3-multidict (4.5.2-1) ... Jan 14 02:12:15 volumio-sk volumio[1016]: info: Setting up libfakeroot:armhf (1.23-1) ... Jan 14 02:12:15 volumio-sk volumio[1016]: info: Setting up python3-async-timeout (3.0.1-1) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up fakeroot (1.23-1) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: using /usr/bin/fakeroot-sysv to provide /usr/bin/fakeroot (fakeroot) in auto mode Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/es/man1/fakeroot.1.gz because associated file /usr/share/man/es/man1/fakeroot-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/es/man1/faked.1.gz because associated file /usr/share/man/es/man1/faked-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/fr/man1/fakeroot.1.gz because associated file /usr/share/man/fr/man1/fakeroot-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/fr/man1/faked.1.gz because associated file /usr/share/man/fr/man1/faked-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/sv/man1/fakeroot.1.gz because associated file /usr/share/man/sv/man1/fakeroot-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: update-alternatives: warning: skip creation of /usr/share/man/sv/man1/faked.1.gz because associated file /usr/share/man/sv/man1/faked-sysv.1.gz (of link group fakeroot) doesn't exist Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up libasan5:armhf (8.3.0-6+rpi1) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up libexpat1-dev:armhf (2.2.6-2+deb10u7) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up make (4.2.1-1.2) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up libmpfr6:armhf (4.0.2-1) ... Jan 14 02:12:16 volumio-sk volumio[1016]: info: Setting up python3-gi (3.30.4-1) ... Jan 14 02:12:17 volumio-sk wpa_supplicant[912]: wlan0: Failed to initiate sched scan Jan 14 02:12:17 volumio-sk volumio[1016]: info: Setting up libmpc3:armhf (1.1.0-1) ... Jan 14 02:12:17 volumio-sk volumio[1016]: info: Setting up patch (2.7.6-3+deb10u1) ... Jan 14 02:12:17 volumio-sk volumio[1016]: info: Setting up libubsan1:armhf (8.3.0-6+rpi1) ... Jan 14 02:12:17 volumio-sk volumio[1016]: info: Setting up libisl19:armhf (0.20-2) ... Jan 14 02:12:18 volumio-sk volumio[1016]: info: Setting up python3-crypto (2.6.1-9+b1) ... Jan 14 02:12:20 volumio-sk volumio[1016]: info: Setting up python-pip-whl (18.1-5+rpt1) ... Jan 14 02:12:20 volumio-sk volumio[1016]: info: Setting up cpp-8 (8.3.0-6+rpi1) ... Jan 14 02:12:20 volumio-sk volumio[1016]: info: Setting up python3-yarl (1.3.0-1) ... Jan 14 02:12:21 volumio-sk volumio[1016]: info: Setting up libalgorithm-diff-xs-perl (0.04-5+b1) ... Jan 14 02:12:21 volumio-sk volumio[1016]: info: Setting up python3-asn1crypto (0.24.0-1) ... Jan 14 02:12:22 volumio-sk volumio[1016]: info: Setting up libcc1-0:armhf (8.3.0-6+rpi1) ... Jan 14 02:12:22 volumio-sk volumio[1016]: info: Setting up python3-cffi-backend (1.12.2-1) ... Jan 14 02:12:22 volumio-sk volumio[1016]: info: Setting up libalgorithm-merge-perl (0.08-3) ... Jan 14 02:12:22 volumio-sk volumio[1016]: info: Setting up libpython3.7-dev:armhf (3.7.3-2+deb10u7) ... Jan 14 02:12:22 volumio-sk volumio[1016]: info: Setting up python3-aiohttp (3.5.1-1+deb10u1) ... Jan 14 02:12:22 volumio-sk wpa_supplicant[912]: wlan0: Failed to initiate sched scan Jan 14 02:12:23 volumio-sk volumio[1016]: info: Setting up python3.7-dev (3.7.3-2+deb10u7) ... Jan 14 02:12:23 volumio-sk volumio[1016]: info: Setting up dpkg-dev (1.19.8) ... Jan 14 02:12:23 volumio-sk volumio[1016]: info: Setting up python3-cryptography (2.6.1-3+deb10u4) ... Jan 14 02:12:25 volumio-sk go-librespot[3822]: time="2025-01-14T02:12:25+05:30" level=error msg="did not receive last pong from dealer, 90s passed" Jan 14 02:12:25 volumio-sk go-librespot[3822]: panic: runtime error: invalid memory address or nil pointer dereference Jan 14 02:12:25 volumio-sk go-librespot[3822]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x43aea8] Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 68 [running]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: panic({0x5a3810, 0x9eea20}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:987 +0x414 fp=0x1ef3e50 sp=0x1ef3df4 pc=0x4ee28 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.panicmem() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:260 +0x4c fp=0x1ef3e5c sp=0x1ef3e50 pc=0x4d5cc Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.sigpanic() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/signal_unix.go:841 +0x26c fp=0x1ef3e78 sp=0x1ef3e5c pc=0x68750 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).writeClose(0x0, 0x3f4, {0x0, 0x0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:54 +0x14 fp=0x1ef3ee4 sp=0x1ef3e7c pc=0x43aea8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).closeHandshake(0x0, 0x3f4, {0x0, 0x0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:37 +0x80 fp=0x1ef3f24 sp=0x1ef3ee4 pc=0x43accc Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Close(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:31 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/dealer.(*Dealer).pingTicker(0x1c743f0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:114 +0x26c fp=0x1ef3fe4 sp=0x1ef3f24 pc=0x4785d4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/dealer.NewDealer.func1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x1ef3fec sp=0x1ef3fe4 pc=0x477d90 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1ef3fec sp=0x1ef3fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/dealer.NewDealer Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x174 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 1 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1d071ec sp=0x1d071d8 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1d072f0, 0x1d072cc, 0x0, 0x0, 0x2, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1d07294 sp=0x1d071ec pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x1d073b4, {0x6cc4c8, 0x1e21440}, 0x0, {0x0, 0x0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x278 fp=0x1d07314 sp=0x1d07294 pc=0x466d4c Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.RetryNotifyWithData[...](...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:54 Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.RetryWithData[...](0x1d073b4, {0x6cc4c8, 0x1e21440}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:43 +0x54 fp=0x1d07340 sp=0x1d07314 pc=0x466aac Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/spclient.(*Spclient).request(0x1ecef60, {0x6189b8, 0x3}, {0x1ce0000, 0x42}, 0x0, 0x1d07480, {0x1d59a80, 0x19b0, 0x19b0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:79 +0x534 fp=0x1d073f0 sp=0x1d07340 pc=0x46464c Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/spclient.(*Spclient).PutConnectState(0x1ecef60, {0x1e281a0, 0xc8}, 0x1e213e0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:122 +0x2d4 fp=0x1d0754c sp=0x1d073f0 pc=0x4650d4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).putConnectState(0x1c26480, 0x4) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/state.go:142 +0x41c fp=0x1d075e8 sp=0x1d0754c pc=0x53d0b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).updateState(0x1c26480) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/state.go:107 +0x24 fp=0x1d0760c sp=0x1d075e8 pc=0x53cbd4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).loadCurrentTrack(0x1c26480, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:132 +0x324 fp=0x1d077a0 sp=0x1d0760c pc=0x5347e8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).advanceNext(0x1c26480, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:371 +0x348 fp=0x1d07824 sp=0x1d077a0 pc=0x536950 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).handlePlayerEvent(0x1c26480, 0x1d079a8) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:52 +0x348 fp=0x1d07890 sp=0x1d07824 pc=0x533d10 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*AppPlayer).Run(0x1c26480, 0x1c62200) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:384 +0x598 fp=0x1d07eac sp=0x1d07890 pc=0x53c484 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*App).withReusableCredentials(0x1da2020, {0x5abe70, 0x1c0e570}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:218 +0x660 fp=0x1d07f3c sp=0x1d07eac pc=0x5382f0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*App).SpotifyToken(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:159 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.main() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:331 +0x524 fp=0x1d07fc0 sp=0x1d07f3c pc=0x538cf8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.main() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:250 +0x268 fp=0x1d07fec sp=0x1d07fc0 pc=0x52288 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1d07fec sp=0x1d07fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 2 [force gc (idle), 7 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f54, 0xa35150, 0x11, 0x14, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3cfd8 sp=0x1c3cfc4 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goparkunlock(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.forcegchelper() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:305 +0xd4 fp=0x1c3cfec sp=0x1c3cfd8 pc=0x525d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3cfec sp=0x1c3cfec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.init.5 Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:293 +0x1c Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 18 [GC sweep wait]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f54, 0xa35750, 0xc, 0x14, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c387c8 sp=0x1c387b4 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goparkunlock(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.bgsweep(0x1c62000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcsweep.go:319 +0x104 fp=0x1c387e4 sp=0x1c387c8 pc=0x3c528 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcenable.func1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x28 fp=0x1c387ec sp=0x1c387e4 pc=0x2cff4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c387ec sp=0x1c387ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcenable Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x74 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 19 [GC scavenge wait]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f54, 0xa35a30, 0xd, 0x14, 0x2) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c38fb4 sp=0x1c38fa0 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goparkunlock(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.(*scavengerState).park(0xa35a30) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:400 +0x64 fp=0x1c38fc8 sp=0x1c38fb4 pc=0x39e1c Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.bgscavenge(0x1c62000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:633 +0x64 fp=0x1c38fe4 sp=0x1c38fc8 pc=0x3a560 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcenable.func2() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0x28 fp=0x1c38fec sp=0x1c38fe4 pc=0x2cfa0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c38fec sp=0x1c38fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcenable Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0xbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 3 [finalizer wait]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642e94, 0xa46af4, 0x10, 0x14, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3c78c sp=0x1c3c778 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.runfinq() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:193 +0xfc fp=0x1c3c7ec sp=0x1c3c78c pc=0x2bed0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3c7ec sp=0x1c3c7ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.createfing Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:163 +0x5c Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 4 [IO wait, 6 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f3c, 0x6dc24f40, 0x2, 0x1b, 0x5) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3d5dc sp=0x1c3d5c8 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.netpollblock(0x6dc24f34, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x1c3d5f4 sp=0x1c3d5dc pc=0x49f2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.runtime_pollWait(0x6dc24f34, 0x72) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x1c3d608 sp=0x1c3d5f4 pc=0x800b4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).wait(0x1c28ec4, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c3d61c sp=0x1c3d608 pc=0xf7db0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).waitRead(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*FD).Accept(0x1c28eb0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:614 +0x2d0 fp=0x1c3d66c sp=0x1c3d61c pc=0xfc8d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*netFD).accept(0x1c28eb0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_unix.go:172 +0x20 fp=0x1c3d6cc sp=0x1c3d66c pc=0x281ba8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPListener).accept(0x1c0e560) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock_posix.go:148 +0x20 fp=0x1c3d6e4 sp=0x1c3d6cc pc=0x29a540 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPListener).Accept(0x1c0e560) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock.go:297 +0x30 fp=0x1c3d700 sp=0x1c3d6e4 pc=0x299504 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*onceCloseListener).Accept(0x1c90040) Jan 14 02:12:25 volumio-sk go-librespot[3822]: :1 +0x34 fp=0x1c3d718 sp=0x1c3d700 pc=0x427558 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*Server).Serve(0x1c9c000, {0x6ccfb0, 0x1c0e560}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3059 +0x344 fp=0x1c3d7b4 sp=0x1c3d718 pc=0x403550 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.Serve(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2581 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*ApiServer).serve(0x1c7d980) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:438 +0x62c fp=0x1c3d7e4 sp=0x1c3d7b4 pc=0x532118 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.NewApiServer.func1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x28 fp=0x1c3d7ec sp=0x1c3d7e4 pc=0x5317d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3d7ec sp=0x1c3d7ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by main.NewApiServer Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x1dc Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 26 [select, 1 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1f71ea0 sp=0x1f71e8c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1f71fac, 0x1f71f94, 0x0, 0x0, 0x2, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1f71f48 sp=0x1f71ea0 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x1cc0a20) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:301 +0x8c fp=0x1f71fe4 sp=0x1f71f48 pc=0x455290 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/ap.NewAccesspoint.func1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x28 fp=0x1f71fec sp=0x1f71fe4 pc=0x453674 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1f71fec sp=0x1f71fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/ap.NewAccesspoint Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x190 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 71 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1d03dd0 sp=0x1d03dbc pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1d03ed0, 0x1d03eb0, 0x0, 0x0, 0x2, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1d03e78 sp=0x1d03dd0 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x1d03f1c, {0x6cc4c8, 0x1e21740}, 0x0, {0x0, 0x0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x268 fp=0x1d03ef4 sp=0x1d03e78 pc=0x450c74 Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x1d03f78, {0x6cc4c8, 0x1e21740}, 0x0, {0x0, 0x0}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x1d03f24 sp=0x1d03ef4 pc=0x45070c Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.RetryNotify(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Jan 14 02:12:25 volumio-sk go-librespot[3822]: github.com/cenkalti/backoff/v4.Retry(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/dealer.(*Dealer).recvLoop(0x1c743f0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:191 +0x564 fp=0x1d03fe4 sp=0x1d03f24 pc=0x478d58 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/dealer.(*Dealer).startReceiving.func1.1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:97 +0x28 fp=0x1d03fec sp=0x1d03fe4 pc=0x47833c Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1d03fec sp=0x1d03fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/dealer.(*Dealer).startReceiving.func1 Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:97 +0x60 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 10 [GC worker (idle)]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642ea0, 0x1c2df20, 0x1a, 0x14, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3e790 sp=0x1c3e77c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcBgMarkWorker() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x1c3e7ec sp=0x1c3e790 pc=0x2fbb8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3e7ec sp=0x1c3e7ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcBgMarkStartWorkers Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 11 [GC worker (idle)]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642ea0, 0x1c2df38, 0x1a, 0x14, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3ef90 sp=0x1c3ef7c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcBgMarkWorker() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x1c3efec sp=0x1c3ef90 pc=0x2fbb8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3efec sp=0x1c3efec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcBgMarkStartWorkers Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 12 [GC worker (idle)]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642ea0, 0x1c2df50, 0x1a, 0x14, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3f790 sp=0x1c3f77c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcBgMarkWorker() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x1c3f7ec sp=0x1c3f790 pc=0x2fbb8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3f7ec sp=0x1c3f7ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcBgMarkStartWorkers Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 13 [GC worker (idle)]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642ea0, 0x1c2df68, 0x1a, 0x14, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3ff90 sp=0x1c3ff7c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gcBgMarkWorker() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x1c3ffec sp=0x1c3ff90 pc=0x2fbb8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3ffec sp=0x1c3ffec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by runtime.gcBgMarkStartWorkers Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 69 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1c3a694 sp=0x1c3a680 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1c3a7b0, 0x1c3a784, 0x0, 0x0, 0x2, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1c3a73c sp=0x1c3a694 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/player.(*Player).manageLoop(0x1dd6840) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/player/player.go:102 +0xd4 fp=0x1c3a7e4 sp=0x1c3a73c pc=0x46922c Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/player.NewPlayer.func2() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x28 fp=0x1c3a7ec sp=0x1c3a7e4 pc=0x469094 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1c3a7ec sp=0x1c3a7ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/player.NewPlayer Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x1bc Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 70 [IO wait, 3 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f3c, 0x6dc24d6c, 0x2, 0x1b, 0x5) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2075d88 sp=0x2075d74 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.netpollblock(0x6dc24d60, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2075da0 sp=0x2075d88 pc=0x49f2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.runtime_pollWait(0x6dc24d60, 0x72) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2075db4 sp=0x2075da0 pc=0x800b4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).wait(0x1ccd1e4, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2075dc8 sp=0x2075db4 pc=0xf7db0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).waitRead(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*FD).Read(0x1ccd1d0, {0x1e5e204, 0x3, 0x3}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2075e18 sp=0x2075dc8 pc=0xf8fbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*netFD).Read(0x1ccd1d0, {0x1e5e204, 0x3, 0x3}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x2075e44 sp=0x2075e18 pc=0x27faec Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*conn).Read(0x1c8f078, {0x1e5e204, 0x3, 0x3}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x2075e74 sp=0x2075e44 pc=0x290a70 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPConn).Read(0x1c8f078, {0x1e5e204, 0x3, 0x3}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: :1 +0x44 fp=0x2075e94 sp=0x2075e74 pc=0x2a514c Jan 14 02:12:25 volumio-sk go-librespot[3822]: io.ReadAtLeast({0x6cb4d4, 0x1c8f078}, {0x1e5e204, 0x3, 0x3}, 0x3) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:332 +0x90 fp=0x2075ec0 sp=0x2075e94 pc=0xf1b18 Jan 14 02:12:25 volumio-sk go-librespot[3822]: io.ReadFull(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:351 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/ap.(*shannonConn).receivePacket(0x2078480) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/shannon.go:80 +0x124 fp=0x2075f20 sp=0x2075ec0 pc=0x457ddc Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/ap.(*Accesspoint).recvLoop(0x1cc0a20) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:239 +0x58 fp=0x2075fe4 sp=0x2075f20 pc=0x454c1c Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/ap.(*Accesspoint).startReceiving.func1.1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:228 +0x28 fp=0x2075fec sp=0x2075fe4 pc=0x454b98 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2075fec sp=0x2075fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/ap.(*Accesspoint).startReceiving.func1 Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:228 +0x60 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 44 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1f706a0 sp=0x1f7068c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1f707bc, 0x1f70774, 0x0, 0x0, 0x5, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1f70748 sp=0x1f706a0 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x1f2e360) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x1f707e4 sp=0x1f70748 pc=0x43d0c8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.newConn.func2() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x1f707ec sp=0x1f707e4 pc=0x43ccbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1f707ec sp=0x1f707ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by nhooyr.io/websocket.newConn Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 62 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1f716a0 sp=0x1f7168c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1f717bc, 0x1f71774, 0x0, 0x0, 0x5, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1f71748 sp=0x1f716a0 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x20c8120) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x1f717e4 sp=0x1f71748 pc=0x43d0c8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.newConn.func2() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x1f717ec sp=0x1f717e4 pc=0x43ccbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1f717ec sp=0x1f717ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by nhooyr.io/websocket.newConn Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 85 [IO wait, 6 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f3c, 0x6dc249c4, 0x2, 0x1b, 0x5) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2070880 sp=0x207086c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.netpollblock(0x6dc249b8, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2070898 sp=0x2070880 pc=0x49f2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.runtime_pollWait(0x6dc249b8, 0x72) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x20708ac sp=0x2070898 pc=0x800b4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).wait(0x1e330f4, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x20708c0 sp=0x20708ac pc=0xf7db0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).waitRead(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*FD).Read(0x1e330e0, {0x1f73000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2070910 sp=0x20708c0 pc=0xf8fbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*netFD).Read(0x1e330e0, {0x1f73000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x207093c sp=0x2070910 pc=0x27faec Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*conn).Read(0x1e7c068, {0x1f73000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x207096c sp=0x207093c pc=0x290a70 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPConn).Read(0x1e7c068, {0x1f73000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: :1 +0x44 fp=0x207098c sp=0x207096c pc=0x2a514c Jan 14 02:12:25 volumio-sk go-librespot[3822]: io.(*multiReader).Read(0x217e5d0, {0x1f73000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/multi.go:26 +0xac fp=0x20709c0 sp=0x207098c pc=0xf2de0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).fill(0x1f0f590) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x20709e4 sp=0x20709c0 pc=0x144f14 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).ReadByte(0x1f0f590) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x20709f0 sp=0x20709e4 pc=0x1457c4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.readFrameHeader(0x1f0f590, {0x1f2e390, 0x8, 0x8}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2070a30 sp=0x20709f0 pc=0x440024 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x1f2e360, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2070af0 sp=0x2070a30 pc=0x442b84 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readLoop(0x1f2e360, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2070bb4 sp=0x2070af0 pc=0x44265c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).reader(0x1f2e360, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x2070c40 sp=0x2070bb4 pc=0x44389c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Reader(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Read(0x1f2e360, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x2070c68 sp=0x2070c40 pc=0x441f28 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*ApiServer).serve.func13({0x6cd0e4, 0x1f20500}, 0x1d1d880) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:418 +0x24c fp=0x2070cc4 sp=0x2070c68 pc=0x5325d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.HandlerFunc.ServeHTTP(0x1c8e068, {0x6cd0e4, 0x1f20500}, 0x1d1d880) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2122 +0x34 fp=0x2070cd4 sp=0x2070cc4 pc=0x40026c Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*ServeMux).ServeHTTP(0x1c94030, {0x6cd0e4, 0x1f20500}, 0x1d1d880) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2500 +0x164 fp=0x2070d00 sp=0x2070cd4 pc=0x401ab4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.serverHandler.ServeHTTP({0x1c9c000}, {0x6cd0e4, 0x1f20500}, 0x1d1d880) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2936 +0x304 fp=0x2070d58 sp=0x2070d00 pc=0x402fc0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*conn).serve(0x1e20300, {0x6cd2ec, 0x1ca2000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:1995 +0x654 fp=0x2070fdc sp=0x2070d58 pc=0x3feb34 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*Server).Serve.func3() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x38 fp=0x2070fec sp=0x2070fdc pc=0x4039f4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2070fec sp=0x2070fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by net/http.(*Server).Serve Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x4e0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 60 [IO wait, 7 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f3c, 0x6dc24a60, 0x2, 0x1b, 0x5) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1ef4880 sp=0x1ef486c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.netpollblock(0x6dc24a54, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x1ef4898 sp=0x1ef4880 pc=0x49f2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.runtime_pollWait(0x6dc24a54, 0x72) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x1ef48ac sp=0x1ef4898 pc=0x800b4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).wait(0x20b43d4, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1ef48c0 sp=0x1ef48ac pc=0xf7db0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).waitRead(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*FD).Read(0x20b43c0, {0x20bd000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x1ef4910 sp=0x1ef48c0 pc=0xf8fbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*netFD).Read(0x20b43c0, {0x20bd000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x1ef493c sp=0x1ef4910 pc=0x27faec Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*conn).Read(0x1c10ad8, {0x20bd000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x1ef496c sp=0x1ef493c pc=0x290a70 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPConn).Read(0x1c10ad8, {0x20bd000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: :1 +0x44 fp=0x1ef498c sp=0x1ef496c pc=0x2a514c Jan 14 02:12:25 volumio-sk go-librespot[3822]: io.(*multiReader).Read(0x1c98740, {0x20bd000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/multi.go:26 +0xac fp=0x1ef49c0 sp=0x1ef498c pc=0xf2de0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).fill(0x20a7770) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x1ef49e4 sp=0x1ef49c0 pc=0x144f14 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).ReadByte(0x20a7770) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x1ef49f0 sp=0x1ef49e4 pc=0x1457c4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.readFrameHeader(0x20a7770, {0x20c8150, 0x8, 0x8}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x1ef4a30 sp=0x1ef49f0 pc=0x440024 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x20c8120, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x1ef4af0 sp=0x1ef4a30 pc=0x442b84 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readLoop(0x20c8120, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x1ef4bb4 sp=0x1ef4af0 pc=0x44265c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).reader(0x20c8120, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x1ef4c40 sp=0x1ef4bb4 pc=0x44389c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Reader(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Read(0x20c8120, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x1ef4c68 sp=0x1ef4c40 pc=0x441f28 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*ApiServer).serve.func13({0x6cd0e4, 0x20c0280}, 0x20be100) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:418 +0x24c fp=0x1ef4cc4 sp=0x1ef4c68 pc=0x5325d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.HandlerFunc.ServeHTTP(0x1c8e068, {0x6cd0e4, 0x20c0280}, 0x20be100) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2122 +0x34 fp=0x1ef4cd4 sp=0x1ef4cc4 pc=0x40026c Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*ServeMux).ServeHTTP(0x1c94030, {0x6cd0e4, 0x20c0280}, 0x20be100) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2500 +0x164 fp=0x1ef4d00 sp=0x1ef4cd4 pc=0x401ab4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.serverHandler.ServeHTTP({0x1c9c000}, {0x6cd0e4, 0x20c0280}, 0x20be100) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2936 +0x304 fp=0x1ef4d58 sp=0x1ef4d00 pc=0x402fc0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*conn).serve(0x20ba240, {0x6cd2ec, 0x1ca2000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:1995 +0x654 fp=0x1ef4fdc sp=0x1ef4d58 pc=0x3feb34 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*Server).Serve.func3() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x38 fp=0x1ef4fec sp=0x1ef4fdc pc=0x4039f4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1ef4fec sp=0x1ef4fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by net/http.(*Server).Serve Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x4e0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 82 [IO wait, 7 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f3c, 0x6dc24afc, 0x2, 0x1b, 0x5) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2073880 sp=0x207386c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.netpollblock(0x6dc24af0, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2073898 sp=0x2073880 pc=0x49f2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.runtime_pollWait(0x6dc24af0, 0x72) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x20738ac sp=0x2073898 pc=0x800b4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).wait(0x1f02014, 0x72, 0x0) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x20738c0 sp=0x20738ac pc=0xf7db0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*pollDesc).waitRead(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 Jan 14 02:12:25 volumio-sk go-librespot[3822]: internal/poll.(*FD).Read(0x1f02000, {0x1f14000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2073910 sp=0x20738c0 pc=0xf8fbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*netFD).Read(0x1f02000, {0x1f14000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x207393c sp=0x2073910 pc=0x27faec Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*conn).Read(0x1f06000, {0x1f14000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x207396c sp=0x207393c pc=0x290a70 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net.(*TCPConn).Read(0x1f06000, {0x1f14000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: :1 +0x44 fp=0x207398c sp=0x207396c pc=0x2a514c Jan 14 02:12:25 volumio-sk go-librespot[3822]: io.(*multiReader).Read(0x1c0e1b0, {0x1f14000, 0x1000, 0x1000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/multi.go:26 +0xac fp=0x20739c0 sp=0x207398c pc=0xf2de0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).fill(0x1f0e060) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x20739e4 sp=0x20739c0 pc=0x144f14 Jan 14 02:12:25 volumio-sk go-librespot[3822]: bufio.(*Reader).ReadByte(0x1f0e060) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x20739f0 sp=0x20739e4 pc=0x1457c4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.readFrameHeader(0x1f0e060, {0x1f2e030, 0x8, 0x8}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2073a30 sp=0x20739f0 pc=0x440024 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x1f2e000, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2073af0 sp=0x2073a30 pc=0x442b84 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).readLoop(0x1f2e000, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2073bb4 sp=0x2073af0 pc=0x44265c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).reader(0x1f2e000, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x2073c40 sp=0x2073bb4 pc=0x44389c Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Reader(...) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).Read(0x1f2e000, {0x6cd2ac, 0x1c2a058}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x2073c68 sp=0x2073c40 pc=0x441f28 Jan 14 02:12:25 volumio-sk go-librespot[3822]: main.(*ApiServer).serve.func13({0x6cd0e4, 0x1f20000}, 0x1f1a000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:418 +0x24c fp=0x2073cc4 sp=0x2073c68 pc=0x5325d0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.HandlerFunc.ServeHTTP(0x1c8e068, {0x6cd0e4, 0x1f20000}, 0x1f1a000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2122 +0x34 fp=0x2073cd4 sp=0x2073cc4 pc=0x40026c Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*ServeMux).ServeHTTP(0x1c94030, {0x6cd0e4, 0x1f20000}, 0x1f1a000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2500 +0x164 fp=0x2073d00 sp=0x2073cd4 pc=0x401ab4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.serverHandler.ServeHTTP({0x1c9c000}, {0x6cd0e4, 0x1f20000}, 0x1f1a000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2936 +0x304 fp=0x2073d58 sp=0x2073d00 pc=0x402fc0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*conn).serve(0x1f08000, {0x6cd2ec, 0x1ca2000}) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:1995 +0x654 fp=0x2073fdc sp=0x2073d58 pc=0x3feb34 Jan 14 02:12:25 volumio-sk go-librespot[3822]: net/http.(*Server).Serve.func3() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x38 fp=0x2073fec sp=0x2073fdc pc=0x4039f4 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2073fec sp=0x2073fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by net/http.(*Server).Serve Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x4e0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 84 [select]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x20a16a0 sp=0x20a168c pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x20a17bc, 0x20a1774, 0x0, 0x0, 0x5, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x20a1748 sp=0x20a16a0 pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x1f2e000) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x20a17e4 sp=0x20a1748 pc=0x43d0c8 Jan 14 02:12:25 volumio-sk go-librespot[3822]: nhooyr.io/websocket.newConn.func2() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x20a17ec sp=0x20a17e4 pc=0x43ccbc Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x20a17ec sp=0x20a17ec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by nhooyr.io/websocket.newConn Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: goroutine 64 [select, 5 minutes]: Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x1ef1c9c sp=0x1ef1c88 pc=0x527b0 Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.selectgo(0x1ef1e1c, 0x1ef1d94, 0x0, 0x0, 0x3, 0x1) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x1ef1d44 sp=0x1ef1c9c pc=0x64d80 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/audio.(*KeyProvider).recvLoop(0x1de4378) Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:52 +0x118 fp=0x1ef1fe4 sp=0x1ef1d44 pc=0x45dd70 Jan 14 02:12:25 volumio-sk go-librespot[3822]: go-librespot/audio.(*KeyProvider).startReceiving.func1.1() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x28 fp=0x1ef1fec sp=0x1ef1fe4 pc=0x45dc2c Jan 14 02:12:25 volumio-sk go-librespot[3822]: runtime.goexit() Jan 14 02:12:25 volumio-sk go-librespot[3822]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x1ef1fec sp=0x1ef1fec pc=0x84730 Jan 14 02:12:25 volumio-sk go-librespot[3822]: created by go-librespot/audio.(*KeyProvider).startReceiving.func1 Jan 14 02:12:25 volumio-sk go-librespot[3822]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x60 Jan 14 02:12:25 volumio-sk volumio[1016]: info: Connection to go-librespot Websocket closed Jan 14 02:12:25 volumio-sk go-librespot[3822]: Aborted Jan 14 02:12:25 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Jan 14 02:12:25 volumio-sk volumio[1016]: info: Connection to go-librespot Websocket closed Jan 14 02:12:25 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:25 volumio-sk volumio[1016]: info: Setting up python3-pip (18.1-5+rpt1) ... Jan 14 02:12:26 volumio-sk volumio[1016]: info: Setting up libgcc-8-dev:armhf (8.3.0-6+rpi1) ... Jan 14 02:12:26 volumio-sk volumio[1016]: info: Setting up cpp (4:8.3.0-1+rpi2) ... Jan 14 02:12:26 volumio-sk volumio[1016]: info: Setting up python3-keyrings.alt (3.1.1-1) ... Jan 14 02:12:27 volumio-sk volumio[1016]: info: Setting up libstdc++-8-dev:armhf (8.3.0-6+rpi1) ... Jan 14 02:12:27 volumio-sk volumio[1016]: info: Setting up gcc-8 (8.3.0-6+rpi1) ... Jan 14 02:12:27 volumio-sk volumio[1016]: info: Setting up libpython3-dev:armhf (3.7.3-1) ... Jan 14 02:12:27 volumio-sk volumio[1016]: info: Setting up gcc (4:8.3.0-1+rpi2) ... Jan 14 02:12:27 volumio-sk volumio[1016]: info: Setting up python3-secretstorage (2.3.1-2) ... Jan 14 02:12:28 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:28 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:28 volumio-sk wpa_supplicant[912]: wlan0: Trying to associate with SSID 'moto g14' Jan 14 02:12:28 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:28 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 14 02:12:28 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:28 volumio-sk go-librespot[5836]: Librespot-go daemon starting... Jan 14 02:12:28 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:28 volumio-sk go-librespot[5836]: time="2025-01-14T02:12:28+05:30" level=info msg="generated new device id: abca9d815ddf5096ffa55d733f16b9ae5cc3bebc" Jan 14 02:12:28 volumio-sk go-librespot[5836]: time="2025-01-14T02:12:28+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:28 volumio-sk go-librespot[5836]: time="2025-01-14T02:12:28+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:28 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:28 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: carrier acquired Jan 14 02:12:28 volumio-sk wpa_supplicant[912]: wlan0: Associated with 96:1d:43:db:42:f3 Jan 14 02:12:28 volumio-sk wpa_supplicant[912]: wlan0: CTRL-EVENT-CONNECTED - Connection to 96:1d:43:db:42:f3 completed [id=0 id_str=] Jan 14 02:12:28 volumio-sk wpa_supplicant[912]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: IAID eb:74:db:8d Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: carrier lost Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: carrier acquired Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: IAID eb:74:db:8d Jan 14 02:12:28 volumio-sk volumio[1016]: info: Setting up python3-dev (3.7.3-1) ... Jan 14 02:12:28 volumio-sk volumio[1016]: info: Setting up g++-8 (8.3.0-6+rpi1) ... Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: rebinding lease of 192.168.150.166 Jan 14 02:12:28 volumio-sk volumio[1016]: info: Setting up python3-keyring (17.1.1-1) ... Jan 14 02:12:28 volumio-sk dhcpcd[928]: wlan0: soliciting an IPv6 router Jan 14 02:12:29 volumio-sk volumio[1016]: info: Setting up g++ (4:8.3.0-1+rpi2) ... Jan 14 02:12:29 volumio-sk volumio[1016]: info: update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode Jan 14 02:12:29 volumio-sk volumio[1016]: info: Setting up build-essential (12.6) ... Jan 14 02:12:29 volumio-sk volumio[1016]: info: Processing triggers for libc-bin (2.28-10+rpt2+rpi1+deb10u2) ... Jan 14 02:12:31 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:31 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:31 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:31 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 14 02:12:31 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:31 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:31 volumio-sk go-librespot[5890]: Librespot-go daemon starting... Jan 14 02:12:31 volumio-sk go-librespot[5890]: time="2025-01-14T02:12:31+05:30" level=info msg="generated new device id: 6ceed7ff248f920978b2b62a2a5d306433011f77" Jan 14 02:12:31 volumio-sk go-librespot[5890]: time="2025-01-14T02:12:31+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:31 volumio-sk go-librespot[5890]: time="2025-01-14T02:12:31+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:31 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:31 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:32 volumio-sk dhcpcd[928]: wlan0: probing address 192.168.150.166/24 Jan 14 02:12:33 volumio-sk sudo[4492]: pam_unix(sudo:session): session closed for user root Jan 14 02:12:33 volumio-sk sudo[5906]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / Jan 14 02:12:33 volumio-sk sudo[5906]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:12:33 volumio-sk volumio[1016]: info: lib/systemd/system/fusiondsp.service Jan 14 02:12:33 volumio-sk sudo[5906]: pam_unix(sudo:session): session closed for user root Jan 14 02:12:33 volumio-sk volumio[1016]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant Jan 14 02:12:33 volumio-sk volumio[1016]: info: more info at http://www.winimage.com/zLibDll/unzip.html Jan 14 02:12:33 volumio-sk volumio[1016]: info: Jan 14 02:12:33 volumio-sk volumio[1016]: info: Cannot open cgui-1.0.0.zip or cgui-1.0.0.zip.zip Jan 14 02:12:33 volumio-sk sudo[5912]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui Jan 14 02:12:33 volumio-sk sudo[5912]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:12:33 volumio-sk sudo[5912]: pam_unix(sudo:session): session closed for user root Jan 14 02:12:33 volumio-sk sudo[5915]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui Jan 14 02:12:33 volumio-sk sudo[5915]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:12:33 volumio-sk sudo[5915]: pam_unix(sudo:session): session closed for user root Jan 14 02:12:33 volumio-sk sudo[5917]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip Jan 14 02:12:33 volumio-sk sudo[5917]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:12:33 volumio-sk sudo[5917]: pam_unix(sudo:session): session closed for user root Jan 14 02:12:34 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:34 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:34 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:34 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 14 02:12:34 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:34 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:34 volumio-sk go-librespot[5920]: Librespot-go daemon starting... Jan 14 02:12:34 volumio-sk go-librespot[5920]: time="2025-01-14T02:12:34+05:30" level=info msg="generated new device id: b10a5abbd5e1ca6ded9c022cd5d7964daca0df69" Jan 14 02:12:34 volumio-sk go-librespot[5920]: time="2025-01-14T02:12:34+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:34 volumio-sk go-librespot[5920]: time="2025-01-14T02:12:34+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:34 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:34 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:37 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:37 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:37 volumio-sk dhcpcd[928]: wlan0: leased 192.168.150.166 for 3600 seconds Jan 14 02:12:38 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:38 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 14 02:12:38 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:38 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:38 volumio-sk go-librespot[5928]: Librespot-go daemon starting... Jan 14 02:12:38 volumio-sk go-librespot[5928]: time="2025-01-14T02:12:38+05:30" level=info msg="generated new device id: 6c26fa02b17b1fc9728b16d36d1fc4ead50d2c70" Jan 14 02:12:38 volumio-sk go-librespot[5928]: time="2025-01-14T02:12:38+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:38 volumio-sk go-librespot[5928]: time="2025-01-14T02:12:38+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:38 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:38 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:40 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:40 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:41 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:41 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 14 02:12:41 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:41 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:41 volumio-sk go-librespot[5939]: Librespot-go daemon starting... Jan 14 02:12:41 volumio-sk go-librespot[5939]: time="2025-01-14T02:12:41+05:30" level=info msg="generated new device id: ea13d2bb3621479430278658aacbee43bbe6d3e4" Jan 14 02:12:41 volumio-sk go-librespot[5939]: time="2025-01-14T02:12:41+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:41 volumio-sk go-librespot[5939]: time="2025-01-14T02:12:41+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:41 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:41 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:43 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:43 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:44 volumio-sk volumiologrotate[649]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Jan 14 02:12:44 volumio-sk volumiologrotate[649]: ls: cannot access 'SK': No such file or directory Jan 14 02:12:44 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:44 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 14 02:12:44 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:44 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:44 volumio-sk go-librespot[6010]: Librespot-go daemon starting... Jan 14 02:12:44 volumio-sk go-librespot[6010]: time="2025-01-14T02:12:44+05:30" level=info msg="generated new device id: a9ac2efcd4f1acd2cf8ea367b3de90e3e6cf0bf6" Jan 14 02:12:44 volumio-sk go-librespot[6010]: time="2025-01-14T02:12:44+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:44 volumio-sk go-librespot[6010]: time="2025-01-14T02:12:44+05:30" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jan 14 02:12:44 volumio-sk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 14 02:12:44 volumio-sk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 14 02:12:45 volumio-sk avahi-daemon[636]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.150.166. Jan 14 02:12:45 volumio-sk dhcpcd[928]: wlan0: adding route to 192.168.150.0/24 Jan 14 02:12:45 volumio-sk dhcpcd[928]: wlan0: adding default route via 192.168.150.80 Jan 14 02:12:45 volumio-sk avahi-daemon[636]: New relevant interface wlan0.IPv4 for mDNS. Jan 14 02:12:45 volumio-sk avahi-daemon[636]: Registering new address record for 192.168.150.166 on wlan0.IPv4. Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Jan 14 02:12:45 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Jan 14 02:12:46 volumio-sk volumio[1016]: info: Discovery: adding 140bbae3-c5c7-4295-90c2-9e0d6de3f2fa Jan 14 02:12:46 volumio-sk volumio[1016]: info: Discovery: Found device Volumio sk Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetState Jan 14 02:12:46 volumio-sk ntpd[797]: Listen normally on 4 wlan0 192.168.150.166:123 Jan 14 02:12:46 volumio-sk ntpd[797]: new interface(s) found: waking up resolver Jan 14 02:12:46 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:46 volumio-sk volumio[1016]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 14 02:12:46 volumio-sk volumio[1016]: verbose: New Socket.io Connection to 192.168.150.166 from 10.212.77.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetVisibleSources Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetState Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 14 02:12:46 volumio-sk volumio[1016]: info: Received Get System Info Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 14 02:12:46 volumio-sk volumio[1016]: info: Discovery: Getting this device information Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetState Jan 14 02:12:46 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 14 02:12:47 volumio-sk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 14 02:12:47 volumio-sk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 14 02:12:47 volumio-sk systemd[1]: Stopped go-librespot Daemon. Jan 14 02:12:47 volumio-sk systemd[1]: Started go-librespot Daemon. Jan 14 02:12:47 volumio-sk go-librespot[6037]: Librespot-go daemon starting... Jan 14 02:12:47 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:47+05:30" level=info msg="generated new device id: 808c83808ff481d5942964f66b5388aac031e290" Jan 14 02:12:47 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:47+05:30" level=debug msg="stored credentials found for 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:53 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetState Jan 14 02:12:53 volumio-sk volumio[1016]: info: Listing playlists Jan 14 02:12:53 volumio-sk volumio[1016]: info: Initializing connection to go-librespot Websocket Jan 14 02:12:53 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 14 02:12:53 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:53+05:30" level=debug msg="new websocket client" Jan 14 02:12:53 volumio-sk volumio[1016]: info: Connection to go-librespot Websocket established Jan 14 02:12:53 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:53+05:30" level=debug msg="obtained new client token: AADEVhG0fS93mFuXFBbQL1DjE6TWQHktSHnTDXiHLpLByYiqwqCRCvyUvRcwVQA7iBptCvC76fojaJeBPgrfUB1VvcjcKFJXA2XAYwDKEIT+HjN+5M/Fd89OrsV7BjYQAIH5ULHg4iJ4IZKPDs+FLhfHvaGPgg/mSyG19iwP8tMRHBUVKrR5rhMzRymyxG2mF8BioivtY3c9UWfMCRQV+MyCCTBG1XYwEfsQ/72javVfzV/Q7/iaOLASWuOH5Bis" Jan 14 02:12:54 volumio-sk ntpd[797]: 139.84.150.88 local addr 192.168.150.166 -> Jan 14 02:12:54 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:54+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 14 02:12:54 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:54+05:30" level=debug msg="completed keyexchange" Jan 14 02:12:55 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:55+05:30" level=debug msg="completed challenge" Jan 14 02:12:55 volumio-sk volumio[1016]: info: Volumio Network Manager: Network status updated: 2 Jan 14 02:12:55 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:55+05:30" level=debug msg="authenticated as 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:55 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:55+05:30" level=debug msg="authenticated as 31rjsijcwxjla4cj3fnsnuncieuy" Jan 14 02:12:55 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:55+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 14 02:12:55 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:55+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="dealer connection opened" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="received connection id: ZTIxZTEyMzMtMGY4MC00ZmU5LWI1MTctMmY4MTk5MWRjNGJhK2RlYWxlcit0Y3A6Ly8wYWM5NDlhYi5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArN0VDMUU4N0FFREUyRkE2MTIzREU5RTRBNUY1NEJENEFCRTA2RkI2OEEwQTc1RDYwMjI4NkM4NkU3MTA0Mjc1Mg==" Jan 14 02:12:56 volumio-sk go-librespot[6037]: time="2025-01-14T02:12:56+05:30" level=debug msg="put connect state because NEW_DEVICE" Jan 14 02:12:56 volumio-sk volumio[1016]: info: Getting Spotify volume Jan 14 02:12:56 volumio-sk volumio[1016]: info: Spotify volume: 100 Jan 14 02:12:56 volumio-sk volumio[1016]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Jan 14 02:12:56 volumio-sk volumio[1016]: info: CoreCommandRouter::volumioGetState Jan 14 02:12:56 volumio-sk volumio[1016]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 14 02:13:05 volumio-sk volumio[1016]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Jan 14 02:13:05 volumio-sk volumio[1016]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 Jan 14 02:13:05 volumio-sk volumio[1016]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-y_1iw0zb Jan 14 02:13:06 volumio-sk volumio[1016]: info: Enabling plugin fusiondsp Jan 14 02:13:06 volumio-sk volumio[1016]: info: Loading plugin "fusiondsp"... Jan 14 02:13:07 volumio-sk volumio[1016]: info: Preparing to generate the ALSA configuration file Jan 14 02:13:07 volumio-sk volumio[1016]: info: Asound.conf file unchanged, so no further update is needed Jan 14 02:13:07 volumio-sk volumio[1016]: info: Output device has changed, restarting MPD Jan 14 02:13:07 volumio-sk sudo[6094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 14 02:13:07 volumio-sk volumio[1016]: info: Output device has changed, restarting Shairport Sync Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 14 02:13:07 volumio-sk sudo[6094]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:07 volumio-sk sudo[6094]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:07 volumio-sk sudo[6096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 14 02:13:07 volumio-sk sudo[6096]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:07 volumio-sk systemd[1]: Stopping Music Player Daemon... Jan 14 02:13:07 volumio-sk volumio[1016]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 14 02:13:07 volumio-sk volumio[1016]: info: PLUGIN START: fusiondsp Jan 14 02:13:07 volumio-sk volumio[1016]: info: Loading i18n strings for locale en Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: FusionDsp - mixtype--------------------- Hardware Jan 14 02:13:07 volumio-sk volumio[1016]: info: Preparing to generate the ALSA configuration file Jan 14 02:13:07 volumio-sk volumio[1016]: info: Done. Jan 14 02:13:07 volumio-sk volumio[1016]: info: MPD Permissions set Jan 14 02:13:07 volumio-sk volumio[1016]: info: Asound.conf file unchanged, so no further update is needed Jan 14 02:13:07 volumio-sk volumio[1016]: info: Output device has changed, restarting MPD Jan 14 02:13:07 volumio-sk systemd[1]: mpd.service: Succeeded. Jan 14 02:13:07 volumio-sk systemd[1]: Stopped Music Player Daemon. Jan 14 02:13:07 volumio-sk sudo[6104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 14 02:13:07 volumio-sk sudo[6104]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:07 volumio-sk volumio[1016]: info: Output device has changed, restarting Shairport Sync Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 14 02:13:07 volumio-sk sudo[6104]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:07 volumio-sk sudo[6106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 14 02:13:07 volumio-sk sudo[6106]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:07 volumio-sk systemd[1]: Starting Music Player Daemon... Jan 14 02:13:07 volumio-sk volumio[1016]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 14 02:13:07 volumio-sk systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 14 02:13:07 volumio-sk systemd[1]: mpd.service: Succeeded. Jan 14 02:13:07 volumio-sk systemd[1]: Stopped Music Player Daemon. Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 14 02:13:07 volumio-sk systemd[1]: Starting Music Player Daemon... Jan 14 02:13:07 volumio-sk volumio[1016]: info: MPD Permissions set Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:07 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk sudo[6112]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 14 02:13:08 volumio-sk sudo[6112]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:08 volumio-sk sudo[6112]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:08 volumio-sk volumio[1016]: info: Starting Shairport Sync Jan 14 02:13:08 volumio-sk volumio[1016]: info: Starting Shairport Sync Jan 14 02:13:08 volumio-sk sudo[6131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 14 02:13:08 volumio-sk sudo[6131]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:08 volumio-sk sudo[6134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 14 02:13:08 volumio-sk sudo[6134]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:08 volumio-sk systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 14 02:13:08 volumio-sk systemd[1]: shairport-sync.service: Succeeded. Jan 14 02:13:08 volumio-sk systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 14 02:13:08 volumio-sk systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 14 02:13:08 volumio-sk sudo[6131]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:08 volumio-sk systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 14 02:13:08 volumio-sk systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jan 14 02:13:08 volumio-sk systemd[1]: shairport-sync.service: Succeeded. Jan 14 02:13:08 volumio-sk systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 14 02:13:09 volumio-sk systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 14 02:13:09 volumio-sk sudo[6134]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:09 volumio-sk volumio[1016]: info: Shairport-Sync Started Jan 14 02:13:09 volumio-sk volumio[1016]: 0+0 records in Jan 14 02:13:09 volumio-sk volumio[1016]: 0+0 records out Jan 14 02:13:09 volumio-sk volumio[1016]: 0 bytes copied, 0.000350123 s, 0.0 kB/s Jan 14 02:13:09 volumio-sk volumio[1016]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Jan 14 02:13:09 volumio-sk volumio[1016]: info: camilladsp service started and running in background, instance 1 Jan 14 02:13:09 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 14 02:13:09 volumio-sk volumio[1016]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 14 02:13:09 volumio-sk volumio[1016]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jan 14 02:13:09 volumio-sk volumio[1016]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 14 02:13:09 volumio-sk volumio[1016]: info: FusionDsp loaded Jan 14 02:13:09 volumio-sk volumio[1016]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 14 02:13:09 volumio-sk sudo[6155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 14 02:13:09 volumio-sk sudo[6155]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 14 02:13:09 volumio-sk volumio[1016]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 14 02:13:09 volumio-sk volumio[1016]: info: Adding Signal Path Element [object Object] Jan 14 02:13:09 volumio-sk volumio[1016]: info: Adding fusiondspeq DSP Signal Path Element Jan 14 02:13:09 volumio-sk volumio[1016]: info: FusionDsp - ---- installed callbackRead Jan 14 02:13:09 volumio-sk volumio[1016]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 14 02:13:10 volumio-sk volumio[1016]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Jan 14 02:13:10 volumio-sk volumio[1016]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Jan 14 02:13:10 volumio-sk volumio[1016]: at onErrorNT (internal/child_process.js:465:16) Jan 14 02:13:10 volumio-sk volumio[1016]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Jan 14 02:13:10 volumio-sk volumio[1016]: errno: -2, Jan 14 02:13:10 volumio-sk volumio[1016]: code: 'ENOENT', Jan 14 02:13:10 volumio-sk volumio[1016]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Jan 14 02:13:10 volumio-sk volumio[1016]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Jan 14 02:13:10 volumio-sk volumio[1016]: spawnargs: [ Jan 14 02:13:10 volumio-sk volumio[1016]: '-p', Jan 14 02:13:10 volumio-sk volumio[1016]: 9876, Jan 14 02:13:10 volumio-sk volumio[1016]: '-o', Jan 14 02:13:10 volumio-sk volumio[1016]: '/tmp/camilladsp.log', Jan 14 02:13:10 volumio-sk volumio[1016]: '-l', Jan 14 02:13:10 volumio-sk volumio[1016]: 'warn', Jan 14 02:13:10 volumio-sk volumio[1016]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Jan 14 02:13:10 volumio-sk volumio[1016]: ] Jan 14 02:13:10 volumio-sk volumio[1016]: } Jan 14 02:13:10 volumio-sk volumio[1016]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 14 02:13:10 volumio-sk systemd[1]: Started FusionDsp Daemon. Jan 14 02:13:10 volumio-sk sudo[6155]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:10 volumio-sk volumio[6158]: /usr/bin/python3: can't open file '/data/plugins/audio_interface/fusiondsp/cgui/main.py': [Errno 2] No such file or directory Jan 14 02:13:10 volumio-sk systemd[1]: fusiondsp.service: Main process exited, code=exited, status=2/INVALIDARGUMENT Jan 14 02:13:10 volumio-sk systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jan 14 02:13:10 volumio-sk mpd[6118]: Jan 14 02:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 14 02:13:10 volumio-sk systemd[1]: Started Music Player Daemon. Jan 14 02:13:10 volumio-sk sudo[6106]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:10 volumio-sk sudo[6096]: pam_unix(sudo:session): session closed for user root Jan 14 02:13:10 volumio-sk sudo[6169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-14 02:12 Jan 14 02:13:10 volumio-sk sudo[6169]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"