May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPause May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::pause May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::stPlaybackTimer May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::servicePause May 27 10:47:57 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 2 May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::servicePause May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 10:47:57 volumio2139 volumio[1151]: info: ControllerMpd::pause May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand pause May 27 10:47:57 volumio2139 volumio[1151]: info: ControllerMpd::getState May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand status May 27 10:47:57 volumio2139 volumio[1151]: info: May 27 10:47:57 volumio2139 volumio[1151]: ---------------------------- MPD announces state update: player May 27 10:47:57 volumio2139 volumio[1151]: info: sendMpdCommand pause took 2 milliseconds May 27 10:47:57 volumio2139 volumio[1151]: info: ControllerMpd::getState May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand status May 27 10:47:57 volumio2139 volumio[1151]: info: sendMpdCommand status took 2 milliseconds May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::parseState May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 10:47:57 volumio2139 volumio[1151]: info: sendMpdCommand status took 2 milliseconds May 27 10:47:57 volumio2139 volumio[1151]: info: sendMpdCommand playlistinfo took 1 milliseconds May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::parseState May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::parseTrackInfo May 27 10:47:57 volumio2139 volumio[1151]: info: Pushing Favourites {"favourite":false} May 27 10:47:57 volumio2139 volumio[1151]: info: sendMpdCommand playlistinfo took 16 milliseconds May 27 10:47:57 volumio2139 volumio[1151]: verbose: ControllerMpd::parseTrackInfo May 27 10:47:57 volumio2139 volumio[1151]: info: ControllerMpd::pushState May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::servicePushState May 27 10:47:57 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 2 May 27 10:47:57 volumio2139 volumio[1151]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":386294,"duration":539,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Django","artist":"Christian Escoudé","album":"Gitane","uri":"http://p456ad.asuscomm.com:8096/Audio/25fad27a3b7884f0f5d56aa60eb1797e/stream.flac?static=true&mediaSourceId=25fad27a3b7884f0f5d56aa60eb1797e&tag=56a4f08cc4e511e85a3954ea30d0f3b3&t.flac","trackType":"flac"} May 27 10:47:57 volumio2139 volumio[1151]: verbose: CURRENT POSITION 2 May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::syncState stateService pause May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::syncState currentStatus pause May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::pushState May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPushState May 27 10:47:57 volumio2139 volumio[1151]: info: MRS: Pushing multiroomSync output update for this device May 27 10:47:57 volumio2139 volumio[1151]: info: MRS: Pushing multiroomSync output May 27 10:47:57 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioGetState May 27 10:47:57 volumio2139 volumio[1151]: info: CoreStateMachine::stPlaybackTimer May 27 10:47:57 volumio2139 volumio5-onboarding[1693]: time=2026-05-27T10:47:57.612+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.31:51570 @ 0xc0003d5e30" state=STATUS_PAUSED positionMs=385087 volume=71 May 27 10:47:57 volumio2139 volumio5-onboarding[1693]: time=2026-05-27T10:47:57.612+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.31:51570 @ 0xc0003d5e30" id="jellyfin/JELL-7443@b69f90bbb9ea49ba8b6f85e2cca331b0/song@songId=3c1ec15a01a072bdd74c58e3fdacc321" title="Det Går En Vind" May 27 10:47:57 volumio2139 volumio[1151]: info: ------------------------------ 50ms May 27 10:47:57 volumio2139 volumio[1151]: info: Pushing Favourites {"service":"mpd","uri":"jellyfin/JELL-7443@b69f90bbb9ea49ba8b6f85e2cca331b0/song@songId=3c1ec15a01a072bdd74c58e3fdacc321","favourite":false} May 27 10:47:57 volumio2139 volumio[1151]: info: [jellyfin-play]: Reported 'pause' for song: Django (at 386294 ms) May 27 10:48:00 volumio2139 volumio[1151]: info: Executing endpoint metavolumio May 27 10:48:00 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 10:48:00 volumio2139 volumio[1151]: info: Executing endpoint metavolumio May 27 10:48:00 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 10:48:03 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: motherearthradio , handleBrowseUri May 27 10:48:03 volumio2139 volumio[1151]: info: Preload queue cleared May 27 10:48:07 volumio2139 volumio[1151]: info: Preload queue cleared May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::ClearQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::stop May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::updateTrackBlock May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrackBlock May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::stPlaybackTimer May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::pushState May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 2 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPushState May 27 10:48:07 volumio2139 volumio[1151]: info: MRS: Pushing multiroomSync output update for this device May 27 10:48:07 volumio2139 volumio[1151]: info: MRS: Pushing multiroomSync output May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioGetState May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 2 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::serviceStop May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 2 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::serviceStop May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 10:48:07 volumio2139 volumio[1151]: info: ControllerMpd::stop May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand stop May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::clearPlayQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::saveQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPushQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::addQueueItems May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::addQueueItems May 27 10:48:07 volumio2139 volumio[1151]: info: Preload queue cleared May 27 10:48:07 volumio2139 volumio[1151]: info: Adding Item to queue: motherearthradio/klassik/mono192 May 27 10:48:07 volumio2139 volumio[1151]: info: Exploding uri motherearthradio/klassik/mono192 in service motherearthradio May 27 10:48:07 volumio2139 volumio5-onboarding[1693]: time=2026-05-27T10:48:07.231+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.31:51570 @ 0xc0003d5e30" state=STATUS_STOPPED positionMs=0 volume=71 May 27 10:48:07 volumio2139 volumio5-onboarding[1693]: time=2026-05-27T10:48:07.231+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.31:51570 @ 0xc0003d5e30" id="jellyfin/JELL-7443@b69f90bbb9ea49ba8b6f85e2cca331b0/song@songId=25fad27a3b7884f0f5d56aa60eb1797e" title=Django May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPushQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::saveQueue May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::updateTrackBlock May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrackBlock May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioGetState May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioPlay May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::play index 0 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::stop May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::play index undefined May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 0 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreStateMachine::startPlaybackTimer May 27 10:48:07 volumio2139 volumio[1151]: info: CorePlayQueue::getTrack 0 May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::volumioGetVisibleSources May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 10:48:07 volumio2139 volumio[1151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 27 10:48:07 volumio2139 volumio[1151]: info: [MER] ▶️ Playing: https://stream.motherearthradio.de/listen/motherearth_klassik/motherearth.klassik.mono May 27 10:48:07 volumio2139 volumio[1151]: info: [MER] 🔌 Starting SSE for Klassik May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand stop May 27 10:48:07 volumio2139 volumio[1151]: info: ControllerMpd::getState May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand status May 27 10:48:07 volumio2139 volumio[1151]: info: May 27 10:48:07 volumio2139 volumio[1151]: ---------------------------- MPD announces state update: player May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand stop took 49 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: info: ControllerMpd::getState May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand status May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand stop took 14 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand clear May 27 10:48:07 volumio2139 volumio[1151]: info: May 27 10:48:07 volumio2139 volumio[1151]: ---------------------------- MPD announces system playlist update May 27 10:48:07 volumio2139 volumio[1151]: info: Ignoring MPD Status Update May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand status took 3 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand status took 2 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand clear took 1 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::parseState May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::parseState May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand add "https://stream.motherearthradio.de/listen/motherearth_klassik/motherearth.klassik.mono" May 27 10:48:07 volumio2139 volumio[1151]: error: updateQueue error: null May 27 10:48:07 volumio2139 volumio[1151]: info: May 27 10:48:07 volumio2139 volumio[1151]: ---------------------------- MPD announces system playlist update May 27 10:48:07 volumio2139 volumio[1151]: info: Ignoring MPD Status Update May 27 10:48:07 volumio2139 volumio[1151]: info: ------------------------------ 3ms May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: info: sendMpdCommand add "https://stream.motherearthradio.de/listen/motherearth_klassik/motherearth.klassik.mono" took 2 milliseconds May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::parseTrackInfo May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::parseTrackInfo May 27 10:48:07 volumio2139 volumio[1151]: verbose: ControllerMpd::sendMpdCommand play May 27 10:48:07 volumio2139 volumio[1151]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 27 10:48:07 volumio2139 volumio[1151]: info: ------------------------------ 13ms May 27 10:48:07 volumio2139 volumio[1151]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 10:48:07 volumio2139 volumio[1151]: TypeError: Cannot read properties of undefined (reading 'split') May 27 10:48:07 volumio2139 volumio[1151]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) May 27 10:48:07 volumio2139 volumio[1151]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 27 10:48:07 volumio2139 volumio[1151]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) May 27 10:48:07 volumio2139 volumio[1151]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 10:48:07 volumio2139 sudo[5808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 10:47' May 27 10:48:07 volumio2139 sudo[5808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"