Apr 11 22:22:08 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:08 cm5 volumio[16276]: info: sendMpdCommand status took 1 milliseconds Apr 11 22:22:18 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:18 cm5 volumio[16276]: info: sendMpdCommand status took 1 milliseconds Apr 11 22:22:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:28 cm5 volumio[16276]: info: sendMpdCommand status took 0 milliseconds Apr 11 22:22:38 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:38 cm5 volumio[16276]: info: sendMpdCommand status took 1 milliseconds Apr 11 22:22:39 cm5 volumio[16276]: info: [HiResProxy] seg 30/41 done Apr 11 22:22:48 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:48 cm5 volumio[16276]: info: sendMpdCommand status took 1 milliseconds Apr 11 22:22:58 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:22:58 cm5 volumio[16276]: info: sendMpdCommand status took 1 milliseconds Apr 11 22:23:08 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:08 cm5 volumio[16276]: info: sendMpdCommand status took 7 milliseconds Apr 11 22:23:18 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:18 cm5 volumio[16276]: info: sendMpdCommand status took 0 milliseconds Apr 11 22:23:19 cm5 volumio[16276]: info: [HiResProxy] seg 40/41 done Apr 11 22:23:23 cm5 volumio[16276]: info: [HiResProxy] seg 41/41 done Apr 11 22:23:23 cm5 volumio[16276]: info: [HiResProxy] stream complete Apr 11 22:23:23 cm5 volumio[16276]: info: [HiResProxy] stream complete — session will expire in 30s: 699a66c632ab5cdb58bee08a Apr 11 22:23:23 cm5 volumio[16276]: info: [HiResProxy] client disconnected, stream cancelled Apr 11 22:23:24 cm5 volumio[16276]: info: Apr 11 22:23:24 cm5 volumio[16276]: ---------------------------- MPD announces state update: player Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::getState Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:24 cm5 volumio[16276]: info: Apr 11 22:23:24 cm5 volumio[16276]: ---------------------------- MPD announces state update: player Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::getState Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:24 cm5 volumio[16276]: info: Apr 11 22:23:24 cm5 volumio[16276]: ---------------------------- MPD announces state update: player Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::getState Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:24 cm5 volumio[16276]: info: sendMpdCommand status took 8 milliseconds Apr 11 22:23:24 cm5 volumio[16276]: info: sendMpdCommand status took 7 milliseconds Apr 11 22:23:24 cm5 volumio[16276]: info: sendMpdCommand status took 6 milliseconds Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::parseState Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::parseState Apr 11 22:23:24 cm5 volumio[16276]: verbose: ControllerMpd::parseState Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::servicePushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreStateMachine::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::volumioPushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current dark_ascendants Received mpd Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::servicePushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreStateMachine::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::volumioPushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current dark_ascendants Received mpd Apr 11 22:23:24 cm5 volumio[16276]: info: ControllerMpd::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::servicePushState Apr 11 22:23:24 cm5 volumio[16276]: info: CoreStateMachine::pushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: CoreCommandRouter::volumioPushState Apr 11 22:23:24 cm5 volumio[16276]: info: CorePlayQueue::getTrack 7 Apr 11 22:23:24 cm5 volumio[16276]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current dark_ascendants Received mpd Apr 11 22:23:24 cm5 volumio[16276]: info: ------------------------------ 24ms Apr 11 22:23:24 cm5 volumio[16276]: info: ------------------------------ 24ms Apr 11 22:23:24 cm5 volumio[16276]: info: ------------------------------ 23ms Apr 11 22:23:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand status Apr 11 22:23:28 cm5 volumio[16276]: info: sendMpdCommand status took 0 milliseconds Apr 11 22:23:28 cm5 volumio[16276]: info: [DarkAscendants] watchdog: MPD state=stop but seekTimer running — attempting resume Apr 11 22:23:28 cm5 volumio[16276]: info: [DarkAscendants] watchdog: Hi-Res — fetching fresh stream URL Apr 11 22:23:28 cm5 volumio[16276]: info: [TidalApi] getStreamUrl[HI_RES_LOSSLESS] trackId=513473485 audioQuality=HI_RES_LOSSLESS mimeType=application/dash+xml encType=NONE api.bitDepth=24 api.sampleRate=96000 Apr 11 22:23:28 cm5 volumio[16276]: info: [TidalApi] getStreamUrl DASH: quality=HI_RES_LOSSLESS codec=flac bitDepth=24 sampleRate=96000 segments=41 initUrl=g1s~XtNDzJQ__&Key-Pair-Id=K14LZCZ9QUI4JL Apr 11 22:23:28 cm5 volumio[16276]: info: [TidalApi] getStreamUrl HiRes proxy registered: http://127.0.0.1:18321/hires/6d889545818b6eedee7c367a Apr 11 22:23:28 cm5 volumio[16276]: info: [DarkAscendants] watchdog: Hi-Res fresh url=http://127.0.0.1:18321/hires/6d889545818b6eedee7c367a Apr 11 22:23:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 22:23:28 cm5 volumio[16276]: info: sendMpdCommand stop took 0 milliseconds Apr 11 22:23:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: info: sendMpdCommand clear took 1 milliseconds Apr 11 22:23:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:18321/hires/6d889545818b6eedee7c367a" Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: error: updateQueue error: null Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: info: ------------------------------ 2ms Apr 11 22:23:28 cm5 volumio[16276]: info: sendMpdCommand add "http://127.0.0.1:18321/hires/6d889545818b6eedee7c367a" took 2 milliseconds Apr 11 22:23:28 cm5 volumio[16276]: info: ------------------------------ 2ms Apr 11 22:23:28 cm5 volumio[16276]: info: ------------------------------ 1ms Apr 11 22:23:28 cm5 volumio[16276]: verbose: ControllerMpd::sendMpdCommand play Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: info: Apr 11 22:23:28 cm5 volumio[16276]: ---------------------------- MPD announces system playlist update Apr 11 22:23:28 cm5 volumio[16276]: info: Ignoring MPD Status Update Apr 11 22:23:28 cm5 volumio[16276]: info: ------------------------------ 3ms Apr 11 22:23:28 cm5 volumio[16276]: info: [HiResProxy] waiting for warmup fetch to complete... Apr 11 22:23:28 cm5 volumio[16276]: info: [HiResProxy] client disconnected, stream cancelled Apr 11 22:23:28 cm5 volumio[16276]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 22:23:28 cm5 volumio[16276]: Error: [5@0] {play} Failed to decode "http://127.0.0.1:18321/hires/6d889545818b6eedee7c367a"; Received HTTP/0.9 when not allowed: Unsupported protocol Apr 11 22:23:28 cm5 volumio[16276]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:17) Apr 11 22:23:28 cm5 volumio[16276]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 11 22:23:28 cm5 volumio[16276]: at Socket.emit (node:events:514:28) Apr 11 22:23:28 cm5 volumio[16276]: at addChunk (node:internal/streams/readable:343:12) Apr 11 22:23:28 cm5 volumio[16276]: at readableAddChunk (node:internal/streams/readable:312:11) Apr 11 22:23:28 cm5 volumio[16276]: at Readable.push (node:internal/streams/readable:253:10) Apr 11 22:23:28 cm5 volumio[16276]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Apr 11 22:23:28 cm5 volumio[16276]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 22:23:28 cm5 sudo[6168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 22:22' Apr 11 22:23:28 cm5 sudo[6168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"