-- Logs begin at Mon 2024-11-18 16:07:21 +07, end at Fri 2024-11-22 18:24:27 +07. -- Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 22 18:23:03 rivokul volumio[3297]: info: Discovery: Getting this device information Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetState Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 22 18:23:03 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:03 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:22 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Nov 22 18:23:23 rivokul volumio[3297]: info: browseTIDALUri took 776 milliseconds Nov 22 18:23:23 rivokul volumio[3297]: info: Preload queue cleared Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990940 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990941 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990942 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990943 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990944 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990945 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990946 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990947 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990948 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990949 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990950 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990951 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990952 Nov 22 18:23:23 rivokul volumio[3297]: info: Preloading song: tidal://song/249990953 Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990940 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990941 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990942 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990943 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990944 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990945 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990946 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990947 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990948 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990949 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990950 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990951 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: explodeTIDALUri took 555 milliseconds Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990952 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: explodeTIDALUri took 574 milliseconds Nov 22 18:23:23 rivokul volumio[3297]: info: Exploding uri tidal://song/249990953 in service tidal Nov 22 18:23:23 rivokul volumio[3297]: info: explodeTIDALUri took 585 milliseconds Nov 22 18:23:23 rivokul volumio[3297]: info: explodeTIDALUri took 562 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 609 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 526 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 648 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 546 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 698 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 562 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 589 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 609 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 665 milliseconds Nov 22 18:23:24 rivokul volumio[3297]: info: explodeTIDALUri took 669 milliseconds Nov 22 18:23:25 rivokul volumio[3297]: info: Executing endpoint getSimilarAlbums Nov 22 18:23:25 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Nov 22 18:23:25 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:25 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:28 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:28 rivokul volumio[3297]: info: Preload queue cleared Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 22 18:23:28 rivokul volumio[3297]: info: CoreStateMachine::ClearQueue Nov 22 18:23:28 rivokul volumio[3297]: info: CoreStateMachine::stop Nov 22 18:23:28 rivokul volumio[3297]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 22 18:23:28 rivokul volumio[3297]: info: CorePlayQueue::clearPlayQueue Nov 22 18:23:28 rivokul volumio[3297]: info: CorePlayQueue::saveQueue Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushQueue Nov 22 18:23:28 rivokul volumio[3297]: info: CoreStateMachine::addQueueItems Nov 22 18:23:28 rivokul volumio[3297]: info: CorePlayQueue::addQueueItems Nov 22 18:23:28 rivokul volumio[3297]: info: Preload queue cleared Nov 22 18:23:28 rivokul volumio[3297]: info: Adding Item to queue: tidal://album/249990939 Nov 22 18:23:28 rivokul volumio[3297]: info: Exploding uri tidal://album/249990939 in service tidal Nov 22 18:23:28 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:28 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:28 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:28 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:28 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:29 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:29 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:29 rivokul volumio[3297]: info: Executing endpoint metavolumio Nov 22 18:23:29 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 22 18:23:29 rivokul volumio[3297]: info: explodeTIDALUri took 872 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushQueue Nov 22 18:23:29 rivokul volumio[3297]: info: CorePlayQueue::saveQueue Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::updateTrackBlock Nov 22 18:23:29 rivokul volumio[3297]: info: CorePlayQueue::getTrackBlock Nov 22 18:23:29 rivokul volumio[3297]: info: CoreCommandRouter::volumioPlay Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::play index 0 Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::stop Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::play index undefined Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 22 18:23:29 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::startPlaybackTimer Nov 22 18:23:29 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:29 rivokul volumio[3297]: info: [1732274609056] ControllerTidal::clearAddPlayTrack Nov 22 18:23:29 rivokul volumio[3297]: info: Getting stream with soundQuality LOSSLESS Nov 22 18:23:29 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand stop Nov 22 18:23:29 rivokul volumio[3297]: info: sendMpdCommand stop took 10 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand clear Nov 22 18:23:29 rivokul volumio[3297]: info: sendMpdCommand clear took 1 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS" Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS" took 6 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 5ms Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 4ms Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 3ms Nov 22 18:23:29 rivokul volumio[3297]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 22 18:23:29 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand play Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: info: Nov 22 18:23:29 rivokul volumio[3297]: ---------------------------- MPD announces system playlist update Nov 22 18:23:29 rivokul volumio[3297]: info: Ignoring MPD Status Update Nov 22 18:23:29 rivokul volumio[3297]: STREAMING PROXY: Handling url /?data=tidal://song/249990940&soundQuality=LOSSLESS Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 6ms Nov 22 18:23:29 rivokul volumio[3297]: info: sendMpdCommand play took 5 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 4ms Nov 22 18:23:29 rivokul volumio[3297]: info: ------------------------------ 3ms Nov 22 18:23:29 rivokul volumio[3297]: info: Executing endpoint getStreamUrltidal Nov 22 18:23:29 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Nov 22 18:23:29 rivokul volumio[3297]: info: getStreamUrl took 767 milliseconds Nov 22 18:23:29 rivokul volumio[3297]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEic2ZmViZWFjN2UzNjU0ZTc4MGUyZWYzMGRkOGI2NmEyMV82MS5tcDQ/0.flac?Expires=1732278209&Signature=dRz2mKmxovREUKxI3VjJBpG3t~FOP9kcuLfosVfmOWH-tEZ9WHiO2Viv6sxr1D1DoX1NpH~9ZYEgYMF1pQc8hVHoEyXBzx~hmd9gbKyL7b9wKpfXzCTTY1rN1uNLZVF0N8bjcQQFxHNDDoHMgjYZmV~rxfnFXQ9FpstSVIaBEV0RlDMo19QKacnYpE7HSEVGz1YN3oTsUw3ZJ33Klc2b688fQZdcWFz4X67nJQ9hGFQqWE3YzTar99otUajTuYH3jC0u4nfRad5vGQ97BU~498isLRVfhHt54uxU1kD3MMddHqNup0bFrz81UZxxsBuj~WskjlXhNeYs6jeY2szU0g__&Key-Pair-Id=K14LZCZ9QUI4JL Nov 22 18:23:30 rivokul volumio[3297]: STREAMING PROXY: Response: 200, length: 21587549 Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 24 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 24 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 23 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: info: Nov 22 18:23:30 rivokul volumio[3297]: ---------------------------- MPD announces state update: player Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::getState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand status Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 6 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 4 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand status took 3 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseTrackInfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseTrackInfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseTrackInfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseState Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus stop Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus play Nov 22 18:23:30 rivokul volumio[3297]: info: Received an update from plugin. extracting info from payload Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus play Nov 22 18:23:30 rivokul volumio[3297]: info: Received an update from plugin. extracting info from payload Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 48ms Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 55ms Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 53ms Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 24 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 22 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: info: sendMpdCommand playlistinfo took 22 milliseconds Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseTrackInfo Nov 22 18:23:30 rivokul volumio[3297]: verbose: ControllerMpd::parseTrackInfo Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus play Nov 22 18:23:30 rivokul volumio[3297]: info: Received an update from plugin. extracting info from payload Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus play Nov 22 18:23:30 rivokul volumio[3297]: info: Received an update from plugin. extracting info from payload Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: ControllerMpd::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::servicePushState Nov 22 18:23:30 rivokul volumio[3297]: info: CorePlayQueue::getTrack 0 Nov 22 18:23:30 rivokul volumio[3297]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"249990940&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/249990940&soundQuality=LOSSLESS","trackType":"tidal"} Nov 22 18:23:30 rivokul volumio[3297]: verbose: CURRENT POSITION 0 Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState stateService play Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::syncState currentStatus play Nov 22 18:23:30 rivokul volumio[3297]: info: Received an update from plugin. extracting info from payload Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreStateMachine::pushState Nov 22 18:23:30 rivokul volumio[3297]: info: CoreCommandRouter::volumioPushState Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 67ms Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 63ms Nov 22 18:23:30 rivokul volumio[3297]: info: ------------------------------ 63ms Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Signalling Playback active due to playback status change Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: Updating RAAT Signal Path Nov 22 18:23:30 rivokul volumio[3297]: info: MCU Signalled Playback Active Nov 22 18:23:30 rivokul volumio[3297]: An internal error occurred while serving an albumart. Details: BadRequestError: request aborted Nov 22 18:23:30 rivokul volumio[3297]: at IncomingMessage.onAborted (/volumio/node_modules/raw-body/index.js:231:10) Nov 22 18:23:30 rivokul volumio[3297]: at IncomingMessage.emit (events.js:400:28) Nov 22 18:23:30 rivokul volumio[3297]: at abortIncoming (_http_server.js:569:9) Nov 22 18:23:30 rivokul volumio[3297]: at socketOnClose (_http_server.js:562:3) Nov 22 18:23:30 rivokul volumio[3297]: at Socket.emit (events.js:412:35) Nov 22 18:23:30 rivokul volumio[3297]: at TCP. (net.js:686:12) Nov 22 18:23:31 rivokul volumio[3297]: error: Failed request for metavolumio API Nov 22 18:23:33 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 22 18:23:33 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 22 18:23:33 rivokul volumio[3297]: info: Discovery: Getting this device information Nov 22 18:23:33 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetState Nov 22 18:23:33 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:34 rivokul volumio[3297]: xcb_connection_has_error() returned true Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 22 18:23:34 rivokul volumio[3297]: xcb_connection_has_error() returned true Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 22 18:23:34 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 22 18:23:38 rivokul volumio[3297]: STREAMING PROXY: Client dropped request, destroying Nov 22 18:23:47 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:47 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:47 rivokul volumio[3297]: info: Retrieving Cloud Streaming UI Nov 22 18:23:47 rivokul volumio[3297]: info: Getting Tidal Cloud Configuration Nov 22 18:23:47 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:47 rivokul volumio[3297]: info: Getting Qobuz Cloud Configuration Nov 22 18:23:47 rivokul volumio[3297]: info: Asking plugin for UI Config Nov 22 18:23:47 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:47 rivokul volumio[3297]: info: Getting Spotify Cloud Configuration Nov 22 18:23:47 rivokul volumio[3297]: info: Asking plugin for UI Config Nov 22 18:23:47 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:47 rivokul volumio[3297]: info: Saving Spotify Acccount Nov 22 18:23:47 rivokul volumio[3297]: info: Got it Nov 22 18:23:47 rivokul volumio[3297]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 22 18:23:48 rivokul volumio[3297]: info: Got Tidal Cloud Configuration Nov 22 18:23:48 rivokul volumio[3297]: info: Got it Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetBrowseSources Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetBrowseSources Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetBrowseSources Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:23:48 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 22 18:23:52 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:23:56 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:00 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:01 rivokul volumio[3297]: info: Disabling MyMusic plugin bluetooth Nov 22 18:24:01 rivokul sudo[13997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumiobt.service Nov 22 18:24:01 rivokul sudo[13997]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 22 18:24:01 rivokul systemd[1]: Stopping Volumio Bluetooth Module... Nov 22 18:24:01 rivokul volumiobt[13999]: Killing pulse Nov 22 18:24:01 rivokul volumio[3297]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 22 18:24:01 rivokul volumiobt[13999]: Killing BT Pair agent Nov 22 18:24:01 rivokul bluetoothd[3210]: Endpoint unregistered: sender=:1.42 path=/MediaEndpoint/A2DPSource Nov 22 18:24:01 rivokul bluetoothd[3210]: Endpoint unregistered: sender=:1.42 path=/MediaEndpoint/A2DPSink Nov 22 18:24:01 rivokul systemd[1]: volumiobt.service: Main process exited, code=killed, status=15/TERM Nov 22 18:24:01 rivokul systemd[1]: volumiobt.service: Succeeded. Nov 22 18:24:01 rivokul systemd[1]: Stopped Volumio Bluetooth Module. Nov 22 18:24:01 rivokul sudo[13997]: pam_unix(sudo:session): session closed for user root Nov 22 18:24:01 rivokul volumio[3297]: info: Volumio BT Module successfully stopped Nov 22 18:24:01 rivokul volumio[3297]: info: Disabling plugin bluetooth Nov 22 18:24:01 rivokul volumio[3297]: info: Done. Nov 22 18:24:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 22 18:24:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 22 18:24:03 rivokul volumio[3297]: info: Discovery: Getting this device information Nov 22 18:24:03 rivokul volumio[3297]: info: CoreCommandRouter::volumioGetState Nov 22 18:24:03 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 22 18:24:04 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:08 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:12 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:16 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:20 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:24 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 22 18:24:26 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Nov 22 18:24:26 rivokul volumio[3297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Nov 22 18:24:26 rivokul volumio[3297]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 18:24:26 rivokul volumio[3297]: Error: getaddrinfo -3007 Nov 22 18:24:26 rivokul volumio[3297]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Nov 22 18:24:26 rivokul volumio[3297]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Nov 22 18:24:26 rivokul volumio[3297]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Nov 22 18:24:26 rivokul volumio[3297]: code: -3007, Nov 22 18:24:26 rivokul volumio[3297]: errno: -3007, Nov 22 18:24:26 rivokul volumio[3297]: syscall: 'getaddrinfo' Nov 22 18:24:26 rivokul volumio[3297]: } Nov 22 18:24:26 rivokul volumio[3297]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 18:24:27 rivokul sudo[14167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-22 18:23 Nov 22 18:24:27 rivokul sudo[14167]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"