-- Logs begin at Fri 2025-12-19 20:31:57 AEDT, end at Fri 2025-12-19 20:43:22 AEDT. -- Dec 19 20:42:06 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Dec 19 20:42:07 primo volumio[3275]: info: handleBrowseUri took 432 milliseconds Dec 19 20:42:07 primo volumio[3275]: info: Preload queue cleared Dec 19 20:42:07 primo volumio[3275]: info: Preload queue cleared Dec 19 20:42:10 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:10.990+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 19 20:42:11 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:11.228+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 19 20:42:17 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Dec 19 20:42:17 primo volumio[3275]: info: handleBrowseUri took 512 milliseconds Dec 19 20:42:17 primo volumio[3275]: info: Preload queue cleared Dec 19 20:42:41 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:41.433+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 19 20:42:41 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:41.603+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 19 20:42:56 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:56.755+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 19 20:42:56 primo volumio5-onboarding[3781]: time=2025-12-19T20:42:56.926+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 19 20:43:06 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Dec 19 20:43:07 primo volumio[3275]: info: handleBrowseUri took 454 milliseconds Dec 19 20:43:07 primo volumio[3275]: info: Preload queue cleared Dec 19 20:43:13 primo volumio[3275]: info: CoreStateMachine::pushState Dec 19 20:43:13 primo volumio[3275]: info: CorePlayQueue::getTrack 0 Dec 19 20:43:13 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 20:43:13 primo volumio[3275]: info: CoreCommandRouter::volumioPushState Dec 19 20:43:13 primo volumio[3275]: info: CoreCommandRouter::volumioGetState Dec 19 20:43:13 primo volumio[3275]: info: CorePlayQueue::getTrack 0 Dec 19 20:43:13 primo volumio[3275]: info: MRS: Pushing multiroomSync output update for this device Dec 19 20:43:13 primo volumio[3275]: info: MRS: Pushing multiroomSync output Dec 19 20:43:13 primo volumio[3275]: info: Updating RAAT Signal Path Dec 19 20:43:13 primo volumio[3275]: info: MCU Signalled Sleep Mode Active Dec 19 20:43:13 primo volumio[3275]: error: Serial API: Failed to decode command: LEDCOLOR, message: 8 Dec 19 20:43:14 primo sudo[5872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force off Dec 19 20:43:14 primo sudo[5872]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 20:43:14 primo kernel: fb: osd[0] enable: 1 (Xorg) Dec 19 20:43:14 primo kernel: fb: osd[0] enable: 0 (Xorg) Dec 19 20:43:14 primo kernel: fb: osd[0] enable: 0 (Xorg) Dec 19 20:43:14 primo sudo[5872]: pam_unix(sudo:session): session closed for user root Dec 19 20:43:14 primo volumio[3275]: info: Enabling Screen Saver via dpms Dec 19 20:43:14 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:14.217+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:14 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:14.518+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:14 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:14.819+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:15 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:15.119+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:15 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:15.420+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:15 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Dec 19 20:43:15 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:15.720+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:16 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:16.020+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:16 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:16.321+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:16 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:16.621+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:16 primo volumio[3275]: info: handleBrowseUri took 1023 milliseconds Dec 19 20:43:16 primo volumio[3275]: info: Preload queue cleared Dec 19 20:43:16 primo volumio[3275]: info: Executing endpoint getSimilarArtists Dec 19 20:43:16 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Dec 19 20:43:16 primo volumio[3275]: info: Executing endpoint getSimilarArtists Dec 19 20:43:16 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Dec 19 20:43:16 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:16.922+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:16 primo volumio[3275]: info: Executing endpoint metavolumio Dec 19 20:43:16 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 19 20:43:16 primo volumio[3275]: info: Executing endpoint metavolumio Dec 19 20:43:16 primo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 19 20:43:17 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:17.343+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 19 20:43:17 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:17.343+11:00 level=ERROR msg="pending write exceeded maximum retries, dropping" component=conn/ble addr=1 chunks=1 index=0 Dec 19 20:43:17 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:17.343+11:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x2c00bd0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Dec 19 20:43:22 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:22.028+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 19 20:43:22 primo volumio[3275]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 20:43:22 primo volumio[3275]: TypeError: Cannot read property 'slice' of null Dec 19 20:43:22 primo volumio[3275]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Dec 19 20:43:22 primo volumio[3275]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Dec 19 20:43:22 primo volumio[3275]: at Object.onceWrapper (events.js:520:26) Dec 19 20:43:22 primo volumio[3275]: at ClientRequest.emit (events.js:400:28) Dec 19 20:43:22 primo volumio[3275]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Dec 19 20:43:22 primo volumio[3275]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Dec 19 20:43:22 primo volumio[3275]: at TLSSocket.socketOnData (_http_client.js:515:22) Dec 19 20:43:22 primo volumio[3275]: at TLSSocket.emit (events.js:400:28) Dec 19 20:43:22 primo volumio[3275]: at addChunk (internal/streams/readable.js:293:12) Dec 19 20:43:22 primo volumio[3275]: at readableAddChunk (internal/streams/readable.js:267:9) Dec 19 20:43:22 primo volumio[3275]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Dec 19 20:43:22 primo volumio[3275]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Dec 19 20:43:22 primo volumio[3275]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 20:43:22 primo volumio5-onboarding[3781]: time=2025-12-19T20:43:22.171+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 19 20:43:22 primo sudo[5901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-19 20:42 Dec 19 20:43:22 primo sudo[5901]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 07:52:21 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="060c5b31331b90c840ee52059a8e3db0"