From ae13a0913c20bb335035fa83ebf3875b731472d2 Mon Sep 17 00:00:00 2001 From: Suyeon Hwang Date: Thu, 15 Feb 2024 21:47:58 +0900 Subject: [PATCH] Fix ducking deactivation retrial logic - Issue: If the ducking deactivation is failed, the retrial for the failure can be performed after a long period of time. - Solution: This patch fixes the logic for the retrial. Through this patch, the code reset the interval of the timer to zero. The deactivation failure should be caused by a minor timing issue, so it will only take a short period of time. So, this patch can make faster the retrial latency. And also this patch includes some minor coding covention fix. Change-Id: I540fb25b7bc2c8b3099046d8bca98b267afa95e4 Signed-off-by: Suyeon Hwang --- server/BackgroundVolume.cpp | 117 ++++++++++++++++++++++++++++---------------- server/BackgroundVolume.h | 2 +- 2 files changed, 75 insertions(+), 44 deletions(-) diff --git a/server/BackgroundVolume.cpp b/server/BackgroundVolume.cpp index c7b578b..69542cf 100644 --- a/server/BackgroundVolume.cpp +++ b/server/BackgroundVolume.cpp @@ -38,12 +38,6 @@ static const char* get_ducking_stream(sound_stream_type_e stream_type) return "Non matched stream"; } -static void ducking_state_changed_cb(sound_stream_ducking_h stream_ducking, bool is_ducked, void *user_data) -{ - SLOG(LOG_DEBUG, tts_tag(), "[BackgroundVolume] is ducked : %d", is_ducked); - return; -} - BackgroundVolume::BackgroundVolume(long long int duckingDuration): mDuckingDuration(duckingDuration), mMediaStream(nullptr), @@ -63,12 +57,15 @@ BackgroundVolume::BackgroundVolume(long long int duckingDuration): BackgroundVolume::~BackgroundVolume() { - long long int diff = getDurationAfterDucking(); + auto diff = getMsecDurationAfterDucking(); if (diff < mDuckingDuration) { - usleep(mDuckingDuration * 1000); + usleep((mDuckingDuration - diff) * 1000); } - deactivateDuckingAll(); + if (false == deactivateDuckingAll()) { + SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] Unknown ducking deactivation failure. One last trial"); + deactivateDuckingAll(); + } if (nullptr != mPostponedModifyTimer) { void* result = ecore_timer_del(mPostponedModifyTimer); @@ -131,22 +128,32 @@ void BackgroundVolume::modifyVolumeOnMainThread(void* data) } if (backgroundVolume->mPostponedModifyTimer != nullptr) { - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Reserved volume modification exist. (%p)", backgroundVolume->mPostponedModifyTimer); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Reserved volume modification exist. (%p)", + backgroundVolume->mPostponedModifyTimer); return; } - long long int diff = backgroundVolume->getDurationAfterDucking(); + auto diff = backgroundVolume->getMsecDurationAfterDucking(); if (diff > backgroundVolume->mDuckingDuration) { double ratio = backgroundVolume->mVolumeRatio.load(); SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Modify volume ratio(%lf) directly", ratio); - backgroundVolume->deactivateDuckingAll(); - backgroundVolume->activateDuckingAll(0, ratio); - } else { - double delay = static_cast(backgroundVolume->mDuckingDuration - diff) / 1000.0; - backgroundVolume->mPostponedModifyTimer = ecore_timer_add(delay, postponedModifyTimerCb, data); - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delay volume modification (%p), delay(%lf)", backgroundVolume->mPostponedModifyTimer, delay); + if (backgroundVolume->deactivateDuckingAll()) { + backgroundVolume->activateDuckingAll(0, ratio); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Volume modification success. ratio(%lf)", ratio); + return; + } else { + SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] Unknown ducking deactivation failure. Try again."); + } + } + + auto delay = 0.0; + if (diff <= backgroundVolume->mDuckingDuration) { + delay = static_cast(backgroundVolume->mDuckingDuration - diff) / 1000.0; } + backgroundVolume->mPostponedModifyTimer = ecore_timer_add(delay, postponedModifyTimerCb, data); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delay volume modification (%p), delay(%lf)", + backgroundVolume->mPostponedModifyTimer, delay); } Eina_Bool BackgroundVolume::postponedModifyTimerCb(void* data) @@ -157,8 +164,13 @@ Eina_Bool BackgroundVolume::postponedModifyTimerCb(void* data) } BackgroundVolume* backgroundVolume = static_cast(data); - double ratio = backgroundVolume->mVolumeRatio.load(); - backgroundVolume->deactivateDuckingAll(); + auto ratio = backgroundVolume->mVolumeRatio.load(); + + if (false == backgroundVolume->deactivateDuckingAll()) { + SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] Unknown ducking deactivation failure. Try again."); + ecore_timer_interval_set(backgroundVolume->mPostponedModifyTimer, 0.0); + return EINA_TRUE; + } backgroundVolume->activateDuckingAll(0, ratio); SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delayed volume modification success. ratio(%lf)", ratio); @@ -253,38 +265,48 @@ void BackgroundVolume::recoverVolumeOnMainThread(void* data) BackgroundVolume* backgroundVolume = static_cast(data); if (nullptr != backgroundVolume->mPostponedRecoverTimer) { - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Reserved volume recover exist. (%p)", backgroundVolume->mPostponedRecoverTimer); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Reserved recover timer already exist. (%p)", + backgroundVolume->mPostponedRecoverTimer); return; } if (nullptr != backgroundVolume->mPostponedModifyTimer) { - void* result = ecore_timer_del(backgroundVolume->mPostponedModifyTimer); + auto result = ecore_timer_del(backgroundVolume->mPostponedModifyTimer); backgroundVolume->mPostponedModifyTimer = nullptr; SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Remove modification timer. result(%p)", result); } - if (false == backgroundVolume->deactivateDuckingAll()) { - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Direct deactivation is failed. Try again after some moments"); - long long int diff = backgroundVolume->getDurationAfterDucking(); - double delay = static_cast(backgroundVolume->mDuckingDuration - diff) / 1000.0; - backgroundVolume->mPostponedRecoverTimer = ecore_timer_add(delay, postponedRecoverTimerCb, data); - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delay deactivation (%p), delay(%lf)", backgroundVolume->mPostponedRecoverTimer, delay); + auto diff = backgroundVolume->getMsecDurationAfterDucking(); + if (diff > backgroundVolume->mDuckingDuration) { + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Direct ducking deactivate"); + if (backgroundVolume->deactivateDuckingAll()) { + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Volume recovery success"); + return; + } else { + SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] Unknown ducking deactivation failure. Try again."); + } + } + + auto delay = 0.0; + if (diff <= backgroundVolume->mDuckingDuration) { + delay = static_cast(backgroundVolume->mDuckingDuration - diff) / 1000.0; } + backgroundVolume->mPostponedRecoverTimer = ecore_timer_add(delay, postponedRecoverTimerCb, data); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delay volume recovery (%p), delay(%lf)", + backgroundVolume->mPostponedRecoverTimer, delay); } -long long int BackgroundVolume::getDurationAfterDucking() +long long int BackgroundVolume::getMsecDurationAfterDucking() { auto currentTime = chrono::steady_clock::now(); - chrono::milliseconds diff = chrono::duration_cast(currentTime - mChangeVolumeTime); - - return diff.count(); + return chrono::duration_cast(currentTime - mChangeVolumeTime).count(); } bool BackgroundVolume::deactivateDuckingAll() { if (false == isDuckingHandleValid()) { SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] There are some invalid handles. Skip ducking deactivation."); - return false; + return true; } bool result = true; @@ -304,11 +326,12 @@ Eina_Bool BackgroundVolume::postponedRecoverTimerCb(void* data) BackgroundVolume* backgroundVolume = static_cast(data); if (false == backgroundVolume->deactivateDuckingAll()) { - SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Try again."); + SLOG(LOG_WARN, tts_tag(), "[BackgroundVolume] Unknown ducking deactivation failure. Try again."); + ecore_timer_interval_set(backgroundVolume->mPostponedRecoverTimer, 0.0); return EINA_TRUE; } - SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delayed unset policy success"); + SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Delayed volume recovery success"); backgroundVolume->mPostponedRecoverTimer = nullptr; return EINA_FALSE; } @@ -332,35 +355,43 @@ bool BackgroundVolume::deactivateDucking(sound_stream_type_e type) return true; } +static void ducking_state_changed_cb(sound_stream_ducking_h stream_ducking, bool is_ducked, void *user_data) +{ + SLOG(LOG_DEBUG, tts_tag(), "[BackgroundVolume] is ducked : %d", is_ducked); +} + int BackgroundVolume::createHandles() { SLOG(LOG_INFO, tts_tag(), "[BackgroundVolume] Create ducking handles"); if (nullptr == mMediaStream) { - int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_MEDIA, - ducking_state_changed_cb, nullptr, &mMediaStream); + int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_MEDIA, ducking_state_changed_cb, nullptr, + &mMediaStream); if (SOUND_MANAGER_ERROR_NONE != ret) { - SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for type media, ret(%d/%s)", ret, get_error_message(ret)); + SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for media, (%d/%s)", + ret, get_error_message(ret)); mMediaStream = nullptr; return TTSD_ERROR_OPERATION_FAILED; } } if (nullptr == mNotificationStream) { - int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_NOTIFICATION, - ducking_state_changed_cb, nullptr, &mNotificationStream); + int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_NOTIFICATION, ducking_state_changed_cb, + nullptr, &mNotificationStream); if (SOUND_MANAGER_ERROR_NONE != ret) { - SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for notification type, ret(%d/%s)", ret, get_error_message(ret)); + SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for notification, (%d/%s)", + ret, get_error_message(ret)); mNotificationStream = nullptr; return TTSD_ERROR_OPERATION_FAILED; } } if (nullptr == mAlarmStream) { - int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_ALARM, - ducking_state_changed_cb, nullptr, &mAlarmStream); + int ret = sound_manager_create_stream_ducking(SOUND_STREAM_TYPE_ALARM, ducking_state_changed_cb, nullptr, + &mAlarmStream); if (SOUND_MANAGER_ERROR_NONE != ret) { - SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for alarm type, ret(%d/%s)", ret, get_error_message(ret)); + SLOG(LOG_ERROR, tts_tag(), "[BackgroundVolume] Fail to create stream ducking for alarm, (%d/%s)", + ret, get_error_message(ret)); mAlarmStream = nullptr; return TTSD_ERROR_OPERATION_FAILED; } diff --git a/server/BackgroundVolume.h b/server/BackgroundVolume.h index 2367abb..05e0680 100644 --- a/server/BackgroundVolume.h +++ b/server/BackgroundVolume.h @@ -43,7 +43,7 @@ private: int createHandles(); bool isDuckingHandleValid(); - long long int getDurationAfterDucking(); + long long int getMsecDurationAfterDucking(); sound_stream_ducking_h getStreamDuckingHandle(sound_stream_type_e type); void activateDuckingAll(unsigned int duration, double ratio); -- 2.7.4