-- Logs begin at Thu 2019-02-14 17:11:59 +07, end at Sat 2026-10-17 17:54:19 +07. -- Oct 17 17:53:17 volumio volumio[901]: info: MRS: Found cast device: SKWAMX3-3b4c203b03894f723a4608ddad5f6c65 Oct 17 17:53:25 volumio volumio[901]: info: CoreCommandRouter::volumioPlay Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::play index undefined Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:53:25 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::startPlaybackTimer Oct 17 17:53:25 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:53:25 volumio volumio[901]: info: [1792234405960] ControllerQobuz::resume Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 17 17:53:25 volumio volumio[901]: info: ControllerMpd::resume Oct 17 17:53:25 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand play Oct 17 17:53:25 volumio volumio[901]: info: Oct 17 17:53:25 volumio volumio[901]: ---------------------------- MPD announces state update: player Oct 17 17:53:25 volumio volumio[901]: info: sendMpdCommand play took 5 milliseconds Oct 17 17:53:25 volumio volumio[901]: info: ControllerMpd::getState Oct 17 17:53:25 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Oct 17 17:53:25 volumio volumio[901]: info: sendMpdCommand status took 2 milliseconds Oct 17 17:53:25 volumio volumio[901]: verbose: ControllerMpd::parseState Oct 17 17:53:25 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 17:53:25 volumio volumio[901]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 17:53:25 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Oct 17 17:53:25 volumio volumio[901]: info: ControllerMpd::pushState Oct 17 17:53:25 volumio volumio[901]: info: CoreCommandRouter::servicePushState Oct 17 17:53:25 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:53:25 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":12741,"duration":148,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2812 Kbps","isStreaming":false,"title":"436444628","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/436444628","trackType":"qobuz"} Oct 17 17:53:25 volumio volumio[901]: verbose: CURRENT POSITION 0 Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus pause Oct 17 17:53:25 volumio volumio[901]: info: CoreStateMachine::pushState Oct 17 17:53:25 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 17:53:25 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Oct 17 17:53:25 volumio volumio[901]: info: MRS: Pushing multiroomSync output update for this device Oct 17 17:53:25 volumio volumio[901]: info: MRS: Pushing multiroomSync output Oct 17 17:53:25 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Oct 17 17:53:25 volumio volumio[901]: info: ------------------------------ 24ms Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::volumioPause Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::pause Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::stPlaybackTimer Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::servicePause Oct 17 17:53:31 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::servicePause Oct 17 17:53:31 volumio volumio[901]: info: [1792234411566] ControllerQobuz::pause Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 17 17:53:31 volumio volumio[901]: info: ControllerMpd::pause Oct 17 17:53:31 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand pause Oct 17 17:53:31 volumio volumio[901]: info: Oct 17 17:53:31 volumio volumio[901]: ---------------------------- MPD announces state update: player Oct 17 17:53:31 volumio volumio[901]: info: sendMpdCommand pause took 2 milliseconds Oct 17 17:53:31 volumio volumio[901]: info: ControllerMpd::getState Oct 17 17:53:31 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Oct 17 17:53:31 volumio volumio[901]: info: sendMpdCommand status took 1 milliseconds Oct 17 17:53:31 volumio volumio[901]: verbose: ControllerMpd::parseState Oct 17 17:53:31 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 17:53:31 volumio volumio[901]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 17:53:31 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Oct 17 17:53:31 volumio volumio[901]: info: ControllerMpd::pushState Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::servicePushState Oct 17 17:53:31 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:53:31 volumio volumio[901]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":18490,"duration":148,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3025 Kbps","isStreaming":false,"title":"436444628","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/436444628","trackType":"qobuz"} Oct 17 17:53:31 volumio volumio[901]: verbose: CURRENT POSITION 0 Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::syncState stateService pause Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus pause Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::pushState Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Oct 17 17:53:31 volumio volumio[901]: info: MRS: Pushing multiroomSync output update for this device Oct 17 17:53:31 volumio volumio[901]: info: MRS: Pushing multiroomSync output Oct 17 17:53:31 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Oct 17 17:53:31 volumio volumio[901]: info: CoreStateMachine::stPlaybackTimer Oct 17 17:53:31 volumio volumio[901]: info: ------------------------------ 22ms Oct 17 17:54:18 volumio volumio[901]: info: Airplay started streaming, receiving metadatas Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioStop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::updateTrackBlock Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrackBlock Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::stPlaybackTimer Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::pushState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output update for this device Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::serviceStop Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::serviceStop Oct 17 17:54:18 volumio volumio[901]: info: [1792234458834] ControllerQobuz::stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 17 17:54:18 volumio volumio[901]: info: ControllerMpd::stop Oct 17 17:54:18 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: Airplay started streaming, receiving metadatas Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioStop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: Airplay started streaming, receiving metadatas Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioStop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: Airplay started streaming, receiving metadatas Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioStop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::stop Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:18 volumio volumio[901]: info: sendMpdCommand stop took 32 milliseconds Oct 17 17:54:18 volumio volumio[901]: info: Oct 17 17:54:18 volumio volumio[901]: ---------------------------- MPD announces state update: player Oct 17 17:54:18 volumio volumio[901]: info: ControllerMpd::getState Oct 17 17:54:18 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Oct 17 17:54:18 volumio volumio[901]: info: sendMpdCommand status took 1 milliseconds Oct 17 17:54:18 volumio volumio[901]: verbose: ControllerMpd::parseState Oct 17 17:54:18 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 17:54:18 volumio volumio[901]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 17:54:18 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Oct 17 17:54:18 volumio volumio[901]: info: ControllerMpd::pushState Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::servicePushState Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::pushState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output update for this device Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 17 17:54:18 volumio volumio[901]: info: ------------------------------ 21ms Oct 17 17:54:18 volumio volumio[901]: info: Updating volume from AirPlay: 0; 100% Oct 17 17:54:18 volumio volumio[901]: info: VolumeController::SetAlsaVolume100 Oct 17 17:54:18 volumio volumio[901]: info: CoreStateMachine::pushState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output update for this device Oct 17 17:54:18 volumio volumio[901]: info: MRS: Pushing multiroomSync output Oct 17 17:54:18 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Oct 17 17:54:18 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:18 volumio shairport-sync[1518]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 17 17:54:19 volumio shairport-sync[1518]: Dload Upload Total Spent Left Speed Oct 17 17:54:19 volumio volumio[901]: info: Oct 17 17:54:19 volumio volumio[901]: ---------------------------- Client requests Start Airplay PlaybackRoutine Oct 17 17:54:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Oct 17 17:54:19 volumio volumio[901]: info: Airplay playback start Oct 17 17:54:19 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Oct 17 17:54:19 volumio volumio[901]: info: CoreCommandRouter::volumioStop Oct 17 17:54:19 volumio volumio[901]: info: CoreStateMachine::stop Oct 17 17:54:19 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:19 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 17:54:19 volumio shairport-sync[1518]: [158B blob data] Oct 17 17:54:19 volumio volumio[901]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 17:54:19 volumio volumio[901]: RangeError [ERR_OUT_OF_RANGE]: The value of "byteLength" is out of range. It must be >= 1 and <= 6. Received 8 Oct 17 17:54:19 volumio volumio[901]: at boundsError (internal/buffer.js:83:9) Oct 17 17:54:19 volumio volumio[901]: at Buffer.readUIntBE (internal/buffer.js:270:3) Oct 17 17:54:19 volumio volumio[901]: at Object.number (/volumio/node_modules/daap-parser/daap-parser.js:33:15) Oct 17 17:54:19 volumio volumio[901]: at Object.tag [as parseTag] (/volumio/node_modules/daap-parser/daap-parser.js:85:37) Oct 17 17:54:19 volumio volumio[901]: at ShairportSyncReaderUDP.useData (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-base.js:89:38) Oct 17 17:54:19 volumio volumio[901]: at Socket. (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-udp.js:21:12) Oct 17 17:54:19 volumio volumio[901]: at Socket.emit (events.js:315:20) Oct 17 17:54:19 volumio volumio[901]: at UDP.onMessage [as onmessage] (dgram.js:919:8) { Oct 17 17:54:19 volumio volumio[901]: code: 'ERR_OUT_OF_RANGE' Oct 17 17:54:19 volumio volumio[901]: } Oct 17 17:54:19 volumio volumio[901]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 17:54:19 volumio sudo[27262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-10-17 17:53 Oct 17 17:54:19 volumio sudo[27262]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"