-- Logs begin at Tue 2026-02-17 17:51:05 MSK, end at Sun 2026-02-22 11:18:57 MSK. -- Feb 22 11:18:09 rivo volumio[3275]: info: CorePlayQueue::getTrack 2 Feb 22 11:18:09 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:09 rivo volumio[3275]: info: Prefetching next song Feb 22 11:18:09 rivo volumio[3275]: info: [1771748289703] ControllerQobuz::prefetch Feb 22 11:18:09 rivo volumio[3275]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/795348" Feb 22 11:18:09 rivo volumio[3275]: STREAMING PROXY: Handling url /?data=qobuz://song/795348 Feb 22 11:18:09 rivo volumio[3275]: info: Executing endpoint getStreamUrlqobuz Feb 22 11:18:09 rivo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 22 11:18:10 rivo volumio[3275]: info: getStreamUrl took 432 milliseconds Feb 22 11:18:10 rivo volumio[3275]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3282062&eid=795348&fmt=6&profile=raw&app_id=539451548&cid=3831380&etsp=1771751890&hmac=o_0ZbNyNUNPlVRF8Wv4eRxymdKc Feb 22 11:18:10 rivo volumio[3275]: STREAMING PROXY: Requesting upstream with range: none Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Upstream status code: 200 Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Client closed connection Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Upstream closed. Received 15646 bytes Feb 22 11:18:11 rivo volumio[3275]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/795348" Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Incomplete transfer. Expected 31921750, got 15646 Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Retrying with range: bytes=15646- (attempt 1) Feb 22 11:18:11 rivo volumio[3275]: info: Feb 22 11:18:11 rivo volumio[3275]: ---------------------------- MPD announces system playlist update Feb 22 11:18:11 rivo volumio[3275]: info: Ignoring MPD Status Update Feb 22 11:18:11 rivo volumio[3275]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/795348" took 4 milliseconds Feb 22 11:18:11 rivo volumio[3275]: STREAMING PROXY: Handling url /?data=qobuz://song/795348 Feb 22 11:18:11 rivo volumio[3275]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 11:18:11 rivo volumio[3275]: verbose: ControllerMpd::sendMpdCommand consume 1 Feb 22 11:18:11 rivo volumio[3275]: info: ------------------------------ 8ms Feb 22 11:18:11 rivo volumio[3275]: info: sendMpdCommand consume 1 took 2 milliseconds Feb 22 11:18:11 rivo volumio[3275]: info: Executing endpoint getStreamUrlqobuz Feb 22 11:18:11 rivo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 22 11:18:12 rivo volumio[3275]: info: getStreamUrl took 331 milliseconds Feb 22 11:18:12 rivo volumio[3275]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3282062&eid=795348&fmt=6&profile=raw&app_id=539451548&cid=3831380&etsp=1771751892&hmac=l_V1rWen4i5XMEGd6h3pUvOdJ5c Feb 22 11:18:12 rivo volumio[3275]: STREAMING PROXY: Requesting upstream with range: none Feb 22 11:18:12 rivo volumio[3275]: STREAMING PROXY: Upstream status code: 200 Feb 22 11:18:12 rivo volumio[3275]: STREAMING PROXY: Resuming with range: bytes=15646- Feb 22 11:18:13 rivo volumio[3275]: STREAMING PROXY: Resume upstream status code: 206 Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::startPlaybackTimer Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::pushState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioPushState Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioGetState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output update for this device Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output Feb 22 11:18:14 rivo volumio5-onboarding[3815]: time=2026-02-22T11:18:14.629+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:56992 @ 0x2892180" state=STATUS_PLAYING positionMs=250 volume=100 Feb 22 11:18:14 rivo volumio5-onboarding[3815]: time=2026-02-22T11:18:14.630+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:56992 @ 0x2892180" id=qobuz://song/795348 title=Jam Feb 22 11:18:14 rivo volumio[3275]: info: Signalling Playback active due to playback status change Feb 22 11:18:14 rivo volumio[3275]: info: Feb 22 11:18:14 rivo volumio[3275]: ---------------------------- MPD announces system playlist update Feb 22 11:18:14 rivo volumio[3275]: info: Ignoring MPD Status Update Feb 22 11:18:14 rivo volumio[3275]: info: Feb 22 11:18:14 rivo volumio[3275]: ---------------------------- MPD announces state update: player Feb 22 11:18:14 rivo volumio[3275]: info: ControllerMpd::getState Feb 22 11:18:14 rivo volumio[3275]: verbose: ControllerMpd::sendMpdCommand status Feb 22 11:18:14 rivo volumio[3275]: info: ------------------------------ 5ms Feb 22 11:18:14 rivo volumio[3275]: info: sendMpdCommand status took 3 milliseconds Feb 22 11:18:14 rivo volumio[3275]: verbose: ControllerMpd::parseState Feb 22 11:18:14 rivo volumio[3275]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 11:18:14 rivo volumio[3275]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 22 11:18:14 rivo volumio[3275]: verbose: ControllerMpd::parseTrackInfo Feb 22 11:18:14 rivo volumio[3275]: info: ControllerMpd::pushState Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::servicePushState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"910 Kbps","isStreaming":false,"title":"795348","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/795348","trackType":"qobuz"} Feb 22 11:18:14 rivo volumio[3275]: verbose: CURRENT POSITION 3 Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::syncState stateService play Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::syncState currentStatus play Feb 22 11:18:14 rivo volumio[3275]: info: Received an update from plugin. extracting info from payload Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::pushState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioPushState Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioGetState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output update for this device Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output Feb 22 11:18:14 rivo volumio[3275]: info: CoreStateMachine::pushState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioPushState Feb 22 11:18:14 rivo volumio[3275]: info: CoreCommandRouter::volumioGetState Feb 22 11:18:14 rivo volumio[3275]: info: CorePlayQueue::getTrack 3 Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output update for this device Feb 22 11:18:14 rivo volumio[3275]: info: MRS: Pushing multiroomSync output Feb 22 11:18:14 rivo volumio5-onboarding[3815]: time=2026-02-22T11:18:14.738+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:56992 @ 0x2892180" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 11:18:14 rivo volumio5-onboarding[3815]: time=2026-02-22T11:18:14.740+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:56992 @ 0x2892180" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 11:18:14 rivo volumio5-onboarding[3815]: time=2026-02-22T11:18:14.741+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:56992 @ 0x2892180" id=qobuz://song/795348 title=Jam Feb 22 11:18:14 rivo volumio[3275]: info: ------------------------------ 53ms Feb 22 11:18:14 rivo volumio[3275]: info: Signalling Playback active due to playback status change Feb 22 11:18:14 rivo volumio[3275]: info: Signalling Playback active due to playback status change Feb 22 11:18:22 rivo volumio[3275]: STREAMING PROXY: Upstream closed. Received 31921750 bytes Feb 22 11:18:22 rivo volumio[3275]: STREAMING PROXY: Client closed connection Feb 22 11:18:27 rivo volumio[3275]: STREAMING PROXY: Resume ended. Received 31906104 bytes Feb 22 11:18:56 rivo volumio[3275]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 11:18:56 rivo volumio[3275]: Error: read ETIMEDOUT Feb 22 11:18:56 rivo volumio[3275]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { Feb 22 11:18:56 rivo volumio[3275]: errno: -110, Feb 22 11:18:56 rivo volumio[3275]: code: 'ETIMEDOUT', Feb 22 11:18:56 rivo volumio[3275]: syscall: 'read' Feb 22 11:18:56 rivo volumio[3275]: } Feb 22 11:18:56 rivo volumio[3275]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 11:18:57 rivo sudo[19543]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-22 11:17 Feb 22 11:18:57 rivo sudo[19543]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 02:25:23 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ab3f2fa07b5f7b8b5e7143217bee70a8"