-- Logs begin at Sat 2025-03-08 13:49:33 CET, end at Sun 2025-03-09 18:30:14 CET. -- Mar 09 18:29:00 volumio volumio[1054]: info: Setting up bzip2 (1.0.6-9.2~deb10u2) ... Mar 09 18:29:00 volumio volumio[1054]: info: Setting up python3-wheel (0.32.3-2) ... Mar 09 18:29:01 volumio volumio[1054]: info: Setting up python3-multidict (4.5.2-1) ... Mar 09 18:29:02 volumio volumio[1054]: info: Setting up libfakeroot:armhf (1.23-1) ... Mar 09 18:29:02 volumio volumio[1054]: info: Setting up python3-async-timeout (3.0.1-1) ... Mar 09 18:29:02 volumio go-librespot[660]: time="2025-03-09T18:29:02+01:00" level=debug msg="fetched chunk 7/18, size: 524288" Mar 09 18:29:03 volumio volumio[1054]: info: Setting up fakeroot (1.23-1) ... Mar 09 18:29:03 volumio volumio[1054]: info: update-alternatives: using /usr/bin/fakeroot-sysv to provide /usr/bin/fakeroot (fakeroot) in auto mode Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: 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 Mar 09 18:29:03 volumio volumio[1054]: info: Setting up libasan5:armhf (8.3.0-6+rpi1) ... Mar 09 18:29:03 volumio volumio[1054]: info: Setting up libexpat1-dev:armhf (2.2.6-2+deb10u7) ... Mar 09 18:29:03 volumio volumio[1054]: info: Setting up make (4.2.1-1.2) ... Mar 09 18:29:03 volumio volumio[1054]: info: Setting up libmpfr6:armhf (4.0.2-1) ... Mar 09 18:29:03 volumio volumio[1054]: info: Setting up python3-gi (3.30.4-1) ... Mar 09 18:29:05 volumio volumio[1054]: info: Setting up libmpc3:armhf (1.1.0-1) ... Mar 09 18:29:05 volumio volumio[1054]: info: Setting up patch (2.7.6-3+deb10u1) ... Mar 09 18:29:05 volumio volumio[1054]: info: Setting up libubsan1:armhf (8.3.0-6+rpi1) ... Mar 09 18:29:05 volumio volumio[1054]: info: Setting up libisl19:armhf (0.20-2) ... Mar 09 18:29:05 volumio volumio[1054]: info: Setting up python3-crypto (2.6.1-9+b1) ... Mar 09 18:29:07 volumio volumio[1054]: info: Setting up python-pip-whl (18.1-5+rpt1) ... Mar 09 18:29:07 volumio volumio[1054]: info: Setting up cpp-8 (8.3.0-6+rpi1) ... Mar 09 18:29:07 volumio volumio[1054]: info: Setting up python3-yarl (1.3.0-1) ... Mar 09 18:29:08 volumio volumio[1054]: info: Setting up libalgorithm-diff-xs-perl (0.04-5+b1) ... Mar 09 18:29:08 volumio volumio[1054]: info: Setting up python3-asn1crypto (0.24.0-1) ... Mar 09 18:29:10 volumio volumio[1054]: info: Setting up libcc1-0:armhf (8.3.0-6+rpi1) ... Mar 09 18:29:10 volumio volumio[1054]: info: Setting up python3-cffi-backend (1.12.2-1) ... Mar 09 18:29:10 volumio volumio[1054]: info: Setting up libalgorithm-merge-perl (0.08-3) ... Mar 09 18:29:10 volumio volumio[1054]: info: Setting up libpython3.7-dev:armhf (3.7.3-2+deb10u7) ... Mar 09 18:29:10 volumio volumio[1054]: info: Setting up python3-aiohttp (3.5.1-1+deb10u1) ... Mar 09 18:29:11 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 09 18:29:11 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 09 18:29:11 volumio volumio[1054]: info: Discovery: Getting this device information Mar 09 18:29:11 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Mar 09 18:29:11 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 09 18:29:12 volumio volumio[1054]: info: Setting up python3.7-dev (3.7.3-2+deb10u7) ... Mar 09 18:29:12 volumio volumio[1054]: info: Setting up dpkg-dev (1.19.8) ... Mar 09 18:29:12 volumio volumio[1054]: info: Setting up python3-cryptography (2.6.1-3+deb10u4) ... Mar 09 18:29:13 volumio go-librespot[660]: time="2025-03-09T18:29:13+01:00" level=debug msg="fetched chunk 8/18, size: 524288" Mar 09 18:29:15 volumio volumio[1054]: info: Setting up python3-pip (18.1-5+rpt1) ... Mar 09 18:29:16 volumio volumio[1054]: info: Setting up libgcc-8-dev:armhf (8.3.0-6+rpi1) ... Mar 09 18:29:16 volumio volumio[1054]: info: Setting up cpp (4:8.3.0-1+rpi2) ... Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=debug msg="seek track to 83602ms" Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=trace msg="seek to 83602ms (diff: 69ms, samples: 3686848, bytes: 3846179)" Mar 09 18:29:16 volumio volumio[1054]: info: Setting up python3-keyrings.alt (3.1.1-1) ... Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:16 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":83602,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:16 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:16 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":83602,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:16 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:16 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:16 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:16 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:16 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:16 volumio go-librespot[660]: time="2025-03-09T18:29:16+01:00" level=debug msg="fetched chunk 9/18, size: 524288" Mar 09 18:29:17 volumio go-librespot[660]: time="2025-03-09T18:29:17+01:00" level=debug msg="fetched chunk 10/18, size: 524288" Mar 09 18:29:17 volumio go-librespot[660]: time="2025-03-09T18:29:17+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:17 volumio go-librespot[660]: time="2025-03-09T18:29:17+01:00" level=debug msg="seek track to 83684ms" Mar 09 18:29:17 volumio go-librespot[660]: time="2025-03-09T18:29:17+01:00" level=trace msg="seek to 83684ms (diff: 87ms, samples: 3690464, bytes: 3850407)" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":83684,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":83684,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:18 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:18 volumio volumio[1054]: info: Setting up libstdc++-8-dev:armhf (8.3.0-6+rpi1) ... Mar 09 18:29:18 volumio volumio[1054]: info: Setting up gcc-8 (8.3.0-6+rpi1) ... Mar 09 18:29:18 volumio volumio[1054]: info: Setting up libpython3-dev:armhf (3.7.3-1) ... Mar 09 18:29:18 volumio volumio[1054]: info: Setting up gcc (4:8.3.0-1+rpi2) ... Mar 09 18:29:18 volumio volumio[1054]: info: Setting up python3-secretstorage (2.3.1-2) ... Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="seek track to 64512ms" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=trace msg="seek to 64512ms (diff: 35ms, samples: 2844979, bytes: 2901705)" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:18 volumio go-librespot[660]: time="2025-03-09T18:29:18+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":64512,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":64512,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:18 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:18 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:18 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=debug msg="seek track to 74166ms" Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=trace msg="seek to 74166ms (diff: 124ms, samples: 3270720, bytes: 3352711)" Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:19 volumio go-librespot[660]: time="2025-03-09T18:29:19+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:19 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":74166,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:19 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:19 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":74166,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:19 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:19 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:19 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:19 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:19 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:19 volumio volumio[1054]: info: Setting up python3-dev (3.7.3-1) ... Mar 09 18:29:20 volumio volumio[1054]: info: Setting up g++-8 (8.3.0-6+rpi1) ... Mar 09 18:29:20 volumio volumio[1054]: info: Setting up python3-keyring (17.1.1-1) ... Mar 09 18:29:20 volumio volumio[1054]: info: Setting up g++ (4:8.3.0-1+rpi2) ... Mar 09 18:29:21 volumio volumio[1054]: info: update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode Mar 09 18:29:21 volumio volumio[1054]: info: Setting up build-essential (12.6) ... Mar 09 18:29:21 volumio volumio[1054]: info: Processing triggers for libc-bin (2.28-10+rpt2+rpi1+deb10u2) ... Mar 09 18:29:21 volumio go-librespot[660]: time="2025-03-09T18:29:21+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:21 volumio go-librespot[660]: time="2025-03-09T18:29:21+01:00" level=debug msg="seek track to 143066ms" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="fetched chunk 12/18, size: 524288" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=trace msg="seek to 143066ms (diff: 130ms, samples: 6309210, bytes: 6701629)" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="fetched chunk 14/18, size: 524288" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="fetched chunk 13/18, size: 524288" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:22 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":143066,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:22 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:22 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":143066,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:22 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:22 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:22 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:22 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:22 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="fetched chunk 15/18, size: 524288" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:22 volumio go-librespot[660]: time="2025-03-09T18:29:22+01:00" level=debug msg="seek track to 157987ms" Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=trace msg="seek to 157987ms (diff: 146ms, samples: 6967226, bytes: 7402189)" Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=debug msg="fetched chunk 17/18, size: 524288" Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:23 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":157987,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:23 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:23 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":157987,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:23 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:23 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:23 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:23 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:23 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:23 volumio go-librespot[660]: time="2025-03-09T18:29:23+01:00" level=debug msg="fetched chunk 16/18, size: 524288" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=debug msg="seek track to 124854ms" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=debug msg="fetched chunk 11/18, size: 524288" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=trace msg="seek to 124854ms (diff: 156ms, samples: 5506061, bytes: 5815113)" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:24 volumio go-librespot[660]: time="2025-03-09T18:29:24+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:24 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":124854,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:24 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:24 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":124854,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:24 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:24 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:24 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:24 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:24 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:27 volumio go-librespot[660]: time="2025-03-09T18:29:27+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:27 volumio go-librespot[660]: time="2025-03-09T18:29:27+01:00" level=debug msg="seek track to 110811ms" Mar 09 18:29:27 volumio go-librespot[660]: time="2025-03-09T18:29:27+01:00" level=trace msg="seek to 110811ms (diff: 96ms, samples: 4886765, bytes: 5125857)" Mar 09 18:29:28 volumio go-librespot[660]: time="2025-03-09T18:29:28+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:28 volumio go-librespot[660]: time="2025-03-09T18:29:28+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:28 volumio go-librespot[660]: time="2025-03-09T18:29:28+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:28 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":110811,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:28 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:28 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":110811,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:28 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:28 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:28 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:28 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:28 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:28 volumio sudo[32416]: pam_unix(sudo:session): session closed for user root Mar 09 18:29:32 volumio kernel: hwmon hwmon1: Voltage normalised Mar 09 18:29:32 volumio sudo[1304]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / Mar 09 18:29:32 volumio sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:29:32 volumio go-librespot[660]: time="2025-03-09T18:29:32+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:32 volumio go-librespot[660]: time="2025-03-09T18:29:32+01:00" level=debug msg="seek track to 141092ms" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=trace msg="seek to 141092ms (diff: 129ms, samples: 6222157, bytes: 6608508)" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":141092,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":141092,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:33 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:33 volumio volumio[1054]: info: lib/systemd/system/fusiondsp.service Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="seek track to 161059ms" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=trace msg="seek to 161059ms (diff: 68ms, samples: 7102701, bytes: 7543007)" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:33 volumio go-librespot[660]: time="2025-03-09T18:29:33+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2Byxr0ooaeLayBBaVLup67","position":161059,"duration":210211,"play_origin":"playlist"}} Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":161059,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:33 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:33 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:33 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:34 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 09 18:29:34 volumio sudo[1304]: pam_unix(sudo:session): session closed for user root Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="handling skip_next player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="skip next track" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="loading track spotify:track:5wVaPZM1qxJUp5pcaVNXII (paused: false, position: 264ms)" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=trace msg="emitting websocket event: will_play" Mar 09 18:29:37 volumio volumio[1054]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5wVaPZM1qxJUp5pcaVNXII","play_origin":"playlist"}} Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5wVaPZM1qxJUp5pcaVNXII" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=debug msg="requested aes key for file 07fdaf1a7fd10078449b3538e453e7e0638b0b15, gid: 5wVaPZM1qxJUp5pcaVNXII" Mar 09 18:29:37 volumio go-librespot[660]: time="2025-03-09T18:29:37+01:00" level=warning msg="failed handling dealer request" error="failed loading current track (skip next): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 2" Mar 09 18:29:38 volumio volumio[1054]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant Mar 09 18:29:38 volumio volumio[1054]: info: more info at http://www.winimage.com/zLibDll/unzip.html Mar 09 18:29:38 volumio volumio[1054]: info: Mar 09 18:29:38 volumio volumio[1054]: info: cgui-1.0.0.zip opened Mar 09 18:29:38 volumio volumio[1054]: info: creating directory: cgui/ Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/LICENSE.txt Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/README.md Mar 09 18:29:38 volumio volumio[1054]: info: creating directory: cgui/build/ Mar 09 18:29:38 volumio sudo[1323]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui Mar 09 18:29:38 volumio sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/robots.txt Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/logo512.png Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/asset-manifest.json Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/index.html Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/.put_statics_here Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/favicon.ico Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/logo192.png Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/.xdp-css-variables-1.css-PvrWoX Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/manifest.json Mar 09 18:29:38 volumio sudo[1323]: pam_unix(sudo:session): session closed for user root Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/css-variables.css Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/precache-manifest.76db5aad1647230454f47b1e22783b54.js Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/service-worker.js Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/precache-manifest.5e6c675b70ef6a3fe73d0209febfe347.js Mar 09 18:29:38 volumio volumio[1054]: info: creating directory: cgui/build/static/ Mar 09 18:29:38 volumio volumio[1054]: info: creating directory: cgui/build/static/css/ Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css.map Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css.map Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css.map Mar 09 18:29:38 volumio sudo[1325]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.1503f6cd.css.map Mar 09 18:29:38 volumio sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css.map Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/main.1503f6cd.css Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css Mar 09 18:29:38 volumio volumio[1054]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css Mar 09 18:29:38 volumio volumio[1054]: info: creating directory: cgui/build/static/media/ Mar 09 18:29:38 volumio sudo[1325]: pam_unix(sudo:session): session closed for user root Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/media/camilladsp.95719842.svg Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/media/camilladsp.4767ea4ad3510467418b818dc677a87e.svg Mar 09 18:29:39 volumio volumio[1054]: info: creating directory: cgui/build/static/js/ Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.map Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.71e11955.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.LICENSE.txt Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js.map Mar 09 18:29:39 volumio go-librespot[660]: time="2025-03-09T18:29:39+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:39 volumio go-librespot[660]: time="2025-03-09T18:29:39+01:00" level=warning msg="failed handling dealer request" error="failed seeking stream: no stream" Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js.map Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.71e11955.js.LICENSE.txt Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.71e11955.js.map Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js.map Mar 09 18:29:39 volumio sudo[1327]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip Mar 09 18:29:39 volumio sudo[1327]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.map Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.LICENSE.txt Mar 09 18:29:39 volumio volumio[1054]: info: creating directory: cgui/config/ Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/config/camillagui.yml Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/config/.xdp-css-variables-1.css-ppBDuX Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/config/gui-config.yml Mar 09 18:29:39 volumio sudo[1327]: pam_unix(sudo:session): session closed for user root Mar 09 18:29:39 volumio volumio[1054]: info: creating directory: cgui/backend/ Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/filters_test.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/version.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/filters.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/settings.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/views.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/filterdefaults.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__init__.py Mar 09 18:29:39 volumio volumio[1054]: info: creating directory: cgui/backend/__pycache__/ Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/filterdefaults.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/views.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/settings.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/__init__.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/routes.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/filemanagement.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/filters.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/__pycache__/version.cpython-37.pyc Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/routes.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/backend/filemanagement.py Mar 09 18:29:39 volumio volumio[1054]: info: extracting: cgui/main.py Mar 09 18:29:40 volumio go-librespot[660]: time="2025-03-09T18:29:40+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:40 volumio go-librespot[660]: time="2025-03-09T18:29:40+01:00" level=warning msg="failed handling dealer request" error="failed seeking stream: no stream" Mar 09 18:29:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 09 18:29:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 09 18:29:41 volumio volumio[1054]: info: Discovery: Getting this device information Mar 09 18:29:41 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Mar 09 18:29:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="handling play player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="loading track spotify:track:1QPbJChjmO2UQC18Ex8Pcg (paused: false, position: 0ms)" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=trace msg="emitting websocket event: will_play" Mar 09 18:29:47 volumio volumio[1054]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","play_origin":"playlist"}} Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1QPbJChjmO2UQC18Ex8Pcg" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="requested aes key for file 32e60c7c3239538fa996342680a236a32a36f2d7, gid: 1QPbJChjmO2UQC18Ex8Pcg" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="fetched first chunk of 14, total size is 6961088 bytes" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=info msg="loaded track \"TOO HOT\" (uri: spotify:track:1QPbJChjmO2UQC18Ex8Pcg, paused: false, position: 0ms, duration: 154593ms)" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=trace msg="emitting websocket event: metadata" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:47 volumio volumio[1054]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","name":"TOO HOT","artist_names":["Sickmode","Rooler"],"album_name":"HEY X2","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b2a75ed6276003366bf95c87","position":0,"duration":154593,"release_date":"year:2021 month:7 day:8","track_number":8,"disc_number":1}} Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="fetched chunk 2/13, size: 524288" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:47 volumio go-librespot[660]: time="2025-03-09T18:29:47+01:00" level=trace msg="emitting websocket event: playing" Mar 09 18:29:47 volumio volumio[1054]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","play_origin":"playlist"}} Mar 09 18:29:47 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:47 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"TOO HOT","artist":"Sickmode, Rooler","album":"HEY X2","albumart":"https://i.scdn.co/image/ab67616d00001e02b2a75ed6276003366bf95c87","uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:47 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:47 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:47 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:47 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:48 volumio go-librespot[660]: time="2025-03-09T18:29:48+01:00" level=debug msg="fetched chunk 1/13, size: 524288" Mar 09 18:29:48 volumio go-librespot[660]: time="2025-03-09T18:29:48+01:00" level=debug msg="fetched chunk 3/13, size: 524288" Mar 09 18:29:48 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:48 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"TOO HOT","artist":"Sickmode, Rooler","album":"HEY X2","albumart":"https://i.scdn.co/image/ab67616d00001e02b2a75ed6276003366bf95c87","uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:48 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:48 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:48 volumio go-librespot[660]: time="2025-03-09T18:29:48+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:48 volumio go-librespot[660]: time="2025-03-09T18:29:48+01:00" level=debug msg="seek track to 31790ms" Mar 09 18:29:48 volumio go-librespot[660]: time="2025-03-09T18:29:48+01:00" level=trace msg="seek to 31790ms (diff: 107ms, samples: 1401939, bytes: 1332423)" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="fetched chunk 4/13, size: 524288" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:49 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","position":31790,"duration":154593,"play_origin":"playlist"}} Mar 09 18:29:49 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:49 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"TOO HOT","artist":"Sickmode, Rooler","album":"HEY X2","albumart":"https://i.scdn.co/image/ab67616d00001e02b2a75ed6276003366bf95c87","uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","trackType":"spotify","seek":31790,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:49 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:49 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:49 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:49 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="fetched chunk 5/13, size: 524288" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="seek track to 50993ms" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=trace msg="seek to 50993ms (diff: 95ms, samples: 2248791, bytes: 2180034)" Mar 09 18:29:49 volumio go-librespot[660]: time="2025-03-09T18:29:49+01:00" level=debug msg="fetched chunk 7/13, size: 524288" Mar 09 18:29:50 volumio go-librespot[660]: time="2025-03-09T18:29:50+01:00" level=debug msg="fetched chunk 6/13, size: 524288" Mar 09 18:29:50 volumio go-librespot[660]: time="2025-03-09T18:29:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:50 volumio go-librespot[660]: time="2025-03-09T18:29:50+01:00" level=trace msg="emitting websocket event: seek" Mar 09 18:29:50 volumio go-librespot[660]: time="2025-03-09T18:29:50+01:00" level=debug msg="sending successful reply for delaer request" Mar 09 18:29:50 volumio volumio[1054]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","position":50993,"duration":154593,"play_origin":"playlist"}} Mar 09 18:29:50 volumio volumio[1054]: SPOTIFY: PUSH STATE SPOTIFY Mar 09 18:29:50 volumio volumio[1054]: SPOTIFY: {"status":"play","service":"spop","title":"TOO HOT","artist":"Sickmode, Rooler","album":"HEY X2","albumart":"https://i.scdn.co/image/ab67616d00001e02b2a75ed6276003366bf95c87","uri":"spotify:track:1QPbJChjmO2UQC18Ex8Pcg","trackType":"spotify","seek":50993,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 09 18:29:50 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Mar 09 18:29:50 volumio volumio[1054]: info: CoreStateMachine::pushState Mar 09 18:29:50 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 18:29:50 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Mar 09 18:29:50 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 09 18:29:53 volumio go-librespot[660]: time="2025-03-09T18:29:53+01:00" level=debug msg="handling play player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:53 volumio go-librespot[660]: time="2025-03-09T18:29:53+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=debug msg="loading track spotify:track:5d2ND4hQ2zyeB3UI6fhn0I (paused: false, position: 215ms)" Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=trace msg="emitting websocket event: will_play" Mar 09 18:29:54 volumio volumio[1054]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5d2ND4hQ2zyeB3UI6fhn0I","play_origin":"playlist"}} Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5d2ND4hQ2zyeB3UI6fhn0I" Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=debug msg="requested aes key for file 5ba7271662ef7374603e7a3dbd16b6f5c4828c46, gid: 5d2ND4hQ2zyeB3UI6fhn0I" Mar 09 18:29:54 volumio go-librespot[660]: time="2025-03-09T18:29:54+01:00" level=warning msg="failed handling dealer request" error="failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 2" Mar 09 18:29:55 volumio volumio[1054]: verbose: New Socket.io Connection to 192.168.0.19 from 192.168.0.31 UA: Mozilla/5.0 (Linux; Android 15; A142 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6943.137 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Mar 09 18:29:55 volumio go-librespot[660]: time="2025-03-09T18:29:55+01:00" level=debug msg="handling seek_to player command from e64910dd981cb51493cca89ced83777a0eb39585" Mar 09 18:29:55 volumio go-librespot[660]: time="2025-03-09T18:29:55+01:00" level=warning msg="failed handling dealer request" error="failed seeking stream: no stream" Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::volumioGetVisibleSources Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::volumioGetQueue Mar 09 18:29:56 volumio volumio[1054]: info: CoreStateMachine::getQueue Mar 09 18:29:56 volumio volumio[1054]: info: CorePlayQueue::getQueue Mar 09 18:29:56 volumio volumio[1054]: info: Listing playlists Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 09 18:29:56 volumio volumio[1054]: info: Received Get System Info Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 09 18:29:56 volumio volumio[1054]: info: Discovery: Getting this device information Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Mar 09 18:29:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 09 18:29:56 volumio volumio[1054]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Mar 09 18:29:56 volumio volumio[1054]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 Mar 09 18:29:56 volumio volumio[1054]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-3zk50fvq Mar 09 18:30:00 volumio volumio[1054]: info: Collecting PyYAML (from camilladsp==1.0.0) Mar 09 18:30:02 volumio volumio[1054]: info: Downloading https://www.piwheels.org/simple/pyyaml/PyYAML-6.0.1-cp37-cp37m-linux_armv7l.whl (45kB) Mar 09 18:30:03 volumio volumio[1054]: info: Collecting websocket_client (from camilladsp==1.0.0) Mar 09 18:30:03 volumio kernel: hwmon hwmon1: Voltage normalised Mar 09 18:30:03 volumio volumio[1054]: info: Downloading https://files.pythonhosted.org/packages/d3/a3/63e9329c8cc9be6153e919e17d0ef5b60d537fed78564872951b95bcc17c/websocket_client-1.6.1-py3-none-any.whl (56kB) Mar 09 18:30:04 volumio volumio[1054]: info: Building wheels for collected packages: camilladsp Mar 09 18:30:04 volumio volumio[1054]: info: Running setup.py bdist_wheel for camilladsp: started Mar 09 18:30:05 volumio volumio[1054]: info: Running setup.py bdist_wheel for camilladsp: finished with status 'done' Mar 09 18:30:05 volumio volumio[1054]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-7t4z66t6/wheels/ca/47/7d/ee36beb671f74869a8e2ecb2c3fd4a28c1b7488a9c78e442b6 Mar 09 18:30:05 volumio volumio[1054]: info: Successfully built camilladsp Mar 09 18:30:05 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 09 18:30:06 volumio volumio[1054]: info: Installing collected packages: PyYAML, websocket-client, camilladsp Mar 09 18:30:07 volumio volumio[1054]: info: Successfully installed PyYAML-6.0.1 camilladsp-1.0.0 websocket-client-1.6.1 Mar 09 18:30:08 volumio volumio[1054]: info: Enabling plugin fusiondsp Mar 09 18:30:08 volumio volumio[1054]: info: Loading plugin "fusiondsp"... Mar 09 18:30:09 volumio volumio[1054]: info: Preparing to generate the ALSA configuration file Mar 09 18:30:09 volumio volumio[1054]: info: Asound.conf file unchanged, so no further update is needed Mar 09 18:30:09 volumio volumio[1054]: info: Output device has changed, restarting MPD Mar 09 18:30:09 volumio sudo[1469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 09 18:30:09 volumio sudo[1469]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:09 volumio volumio[1054]: info: Output device has changed, restarting Shairport Sync Mar 09 18:30:09 volumio sudo[1469]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 09 18:30:09 volumio sudo[1472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 09 18:30:09 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:09 volumio volumio[1054]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 09 18:30:09 volumio volumio[1054]: info: PLUGIN START: fusiondsp Mar 09 18:30:09 volumio systemd[1]: Stopping Music Player Daemon... Mar 09 18:30:09 volumio volumio[1054]: info: Loading i18n strings for locale it Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:09 volumio volumio[1054]: info: FusionDsp - mixtype--------------------- Hardware Mar 09 18:30:09 volumio volumio[1054]: info: Preparing to generate the ALSA configuration file Mar 09 18:30:09 volumio volumio[1054]: info: Done. Mar 09 18:30:09 volumio volumio[1054]: info: MPD Permissions set Mar 09 18:30:09 volumio volumio[1054]: info: Asound.conf file unchanged, so no further update is needed Mar 09 18:30:09 volumio volumio[1054]: info: Output device has changed, restarting MPD Mar 09 18:30:09 volumio volumio[1054]: info: Output device has changed, restarting Shairport Sync Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 09 18:30:09 volumio sudo[1480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 09 18:30:09 volumio sudo[1478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 09 18:30:09 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:09 volumio sudo[1478]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:09 volumio sudo[1478]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:09 volumio volumio[1054]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 09 18:30:10 volumio volumio[1054]: info: MPD Permissions set Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio systemd[1]: mpd.service: Succeeded. Mar 09 18:30:10 volumio systemd[1]: Stopped Music Player Daemon. Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:10 volumio volumio[1054]: info: Starting Shairport Sync Mar 09 18:30:10 volumio systemd[1]: Starting Music Player Daemon... Mar 09 18:30:10 volumio sudo[1497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 09 18:30:10 volumio sudo[1497]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:10 volumio volumio[1054]: info: FusionDsp - Mar 09 18:30:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 09 18:30:10 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 09 18:30:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 09 18:30:10 volumio sudo[1494]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 09 18:30:10 volumio sudo[1494]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 09 18:30:10 volumio sudo[1494]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:10 volumio sudo[1497]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:10 volumio volumio[1054]: info: FusionDsp - Mar 09 18:30:11 volumio volumio[1054]: info: FusionDsp - Mar 09 18:30:12 volumio volumio[1054]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Mar 09 18:30:12 volumio volumio[1054]: info: camilladsp service started and running in background, instance 1 Mar 09 18:30:12 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 09 18:30:12 volumio volumio[1054]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Mar 09 18:30:12 volumio volumio[1054]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Mar 09 18:30:12 volumio volumio[1054]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Mar 09 18:30:12 volumio volumio[1054]: info: FusionDsp loaded Mar 09 18:30:12 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 09 18:30:12 volumio sudo[1515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Mar 09 18:30:12 volumio sudo[1515]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 09 18:30:12 volumio volumio[1054]: info: FusionDsp - Reporting Fusion DSP Enabled Mar 09 18:30:12 volumio volumio[1054]: info: Adding Signal Path Element [object Object] Mar 09 18:30:12 volumio volumio[1054]: info: Adding fusiondspeq DSP Signal Path Element Mar 09 18:30:12 volumio volumio[1054]: info: FusionDsp - ---- installed callbackRead Mar 09 18:30:12 volumio volumio[1054]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 09 18:30:12 volumio systemd[1]: Started FusionDsp Daemon. Mar 09 18:30:12 volumio sudo[1515]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:12 volumio volumio[1054]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Mar 09 18:30:12 volumio volumio[1054]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Mar 09 18:30:12 volumio volumio[1054]: at onErrorNT (internal/child_process.js:465:16) Mar 09 18:30:12 volumio volumio[1054]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 09 18:30:12 volumio volumio[1054]: at runNextTicks (internal/process/task_queues.js:62:3) Mar 09 18:30:12 volumio volumio[1054]: at listOnTimeout (internal/timers.js:523:9) Mar 09 18:30:12 volumio volumio[1054]: at processTimers (internal/timers.js:497:7) { Mar 09 18:30:12 volumio volumio[1054]: errno: -2, Mar 09 18:30:12 volumio volumio[1054]: code: 'ENOENT', Mar 09 18:30:12 volumio volumio[1054]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Mar 09 18:30:12 volumio volumio[1054]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Mar 09 18:30:12 volumio volumio[1054]: spawnargs: [ Mar 09 18:30:12 volumio volumio[1054]: '-p', Mar 09 18:30:12 volumio volumio[1054]: 9876, Mar 09 18:30:12 volumio volumio[1054]: '-o', Mar 09 18:30:12 volumio volumio[1054]: '/tmp/camilladsp.log', Mar 09 18:30:12 volumio volumio[1054]: '-l', Mar 09 18:30:12 volumio volumio[1054]: 'warn', Mar 09 18:30:12 volumio volumio[1054]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Mar 09 18:30:12 volumio volumio[1054]: ] Mar 09 18:30:12 volumio volumio[1054]: } Mar 09 18:30:12 volumio volumio[1054]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 09 18:30:14 volumio mpd[1502]: Mar 09 18:30 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 09 18:30:14 volumio systemd[1]: Started Music Player Daemon. Mar 09 18:30:14 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:14 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root Mar 09 18:30:14 volumio sudo[1529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-09 18:29 Mar 09 18:30:14 volumio sudo[1529]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"