From: Ji-hoon Lee Date: Tue, 16 Jul 2024 02:41:15 +0000 (+0900) Subject: Make log recorder to store main thread messages separately X-Git-Tag: accepted/tizen/unified/20241106.141127~2 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=refs%2Fchanges%2F02%2F314602%2F1;p=platform%2Fcore%2Fuifw%2Fmulti-assistant-service.git Make log recorder to store main thread messages separately Change-Id: I4d8e11562668654bf0e3dcf79bd40fa4ea089d9a --- diff --git a/src/service_ipc_dbus.cpp b/src/service_ipc_dbus.cpp index fa51a91..0e30c72 100644 --- a/src/service_ipc_dbus.cpp +++ b/src/service_ipc_dbus.cpp @@ -1364,6 +1364,7 @@ static Eina_Bool listener_event_callback(void* data, Ecore_Fd_Handler *fd_handle num_messages++; } + print_duration(num_messages, started); return ECORE_CALLBACK_RENEW; } diff --git a/wakeup-manager/inc/log_recorder.h b/wakeup-manager/inc/log_recorder.h index 725d2f1..6f84696 100644 --- a/wakeup-manager/inc/log_recorder.h +++ b/wakeup-manager/inc/log_recorder.h @@ -29,11 +29,15 @@ private: private: const int MAX_LOG_MESSAGES = 100; - const int MAX_TIMER_COUNTER = 10; + const int MAX_TIMER_COUNTER = 8; std::mutex mMutex; - std::list mMessages; + std::list mMainMessages; + std::list mAllMessages; std::thread mPrintThread; + std::thread::id mMainThreadId; + std::atomic_bool mInitialized{false}; std::atomic_bool mIsRunning{false}; + std::atomic_bool mIsPrinting{false}; std::atomic_int mCounter{0}; }; diff --git a/wakeup-manager/inc/wakeup_audio_manager.h b/wakeup-manager/inc/wakeup_audio_manager.h index b793faa..140e5ae 100644 --- a/wakeup-manager/inc/wakeup_audio_manager.h +++ b/wakeup-manager/inc/wakeup_audio_manager.h @@ -64,6 +64,9 @@ public: int initialize(); int deinitialize(); + int activate(); + int deactivate(); + void sound_focus_changed(); /* NOTE : The observer that is being passed to this subscribe() function diff --git a/wakeup-manager/src/log_recorder.cpp b/wakeup-manager/src/log_recorder.cpp index 6b37fb5..0c5c7af 100644 --- a/wakeup-manager/src/log_recorder.cpp +++ b/wakeup-manager/src/log_recorder.cpp @@ -3,6 +3,7 @@ #include #include +#include #include #include @@ -18,7 +19,8 @@ LogRecorder& LogRecorder::getInstance() LogRecorder::LogRecorder() { - mMessages.assign(MAX_LOG_MESSAGES, std::string()); + mMainMessages.assign(MAX_LOG_MESSAGES, std::string()); + mAllMessages.assign(MAX_LOG_MESSAGES, std::string()); } LogRecorder::~LogRecorder() @@ -91,6 +93,9 @@ void LogRecorder::initialize() { mCounter.store(0); mIsRunning.store(true); + mIsPrinting.store(false); + mMainThreadId = std::this_thread::get_id(); + mPrintThread = std::thread([this]() { pthread_t thread = pthread_self(); pthread_setname_np(thread, "log-recorder-thread"); @@ -99,34 +104,56 @@ void LogRecorder::initialize() std::this_thread::sleep_for(std::chrono::seconds(1)); mCounter.fetch_add(1); if (mCounter.load() > MAX_TIMER_COUNTER) { + mIsPrinting.store(true); dlog_print(DLOG_ERROR, LOG_TAG, "Counter : %d, printing recorded logs ===", mCounter.load()); + std::cerr << "Counter : " << mCounter.load() << "printing recorded logs ===" << std::endl; std::lock_guard lock(mMutex); - for (auto message : mMessages) { + int index = 0; + for (auto message : mMainMessages) { + std::this_thread::sleep_for(std::chrono::milliseconds(10)); + dlog_print(DLOG_ERROR, LOG_TAG, "M[%d], %s", ++index, message.c_str()); std::this_thread::sleep_for(std::chrono::milliseconds(10)); - dlog_print(DLOG_ERROR, LOG_TAG, "%s", message.c_str()); + std::cerr << message << std::endl; + if (mCounter.load() <= 0) { + break; + } + } + index = 0; + for (auto message : mAllMessages) { + std::this_thread::sleep_for(std::chrono::milliseconds(10)); + dlog_print(DLOG_ERROR, LOG_TAG, "A[%d], %s", ++index, message.c_str()); if (mCounter <= 0) { break; } } - mCounter.store(0); dlog_print(DLOG_ERROR, LOG_TAG, "Counter is now 0, printed recorded logs ==="); + std::cerr << "Counter is now 0, printed recorded logs ===" << std::endl; print_esp_eip(); + + mCounter.store(0); + mIsPrinting.store(false); } if (localCounter++ > 10) { dlog_print(DLOG_ERROR, LOG_TAG, "Log recorder is running"); + std::this_thread::sleep_for(std::chrono::milliseconds(10)); + std::cerr << "Log recorder is running" << std::endl; localCounter = 0; } } }); + mInitialized.store(true); } void LogRecorder::deinitialize() { mCounter.store(0); mIsRunning.store(false); - mPrintThread.join(); + if (mPrintThread.joinable()) { + mPrintThread.join(); + } + mInitialized.store(false); } void LogRecorder::resetCounter() @@ -136,6 +163,8 @@ void LogRecorder::resetCounter() void LogRecorder::addMessage(const char *format, ...) { + if (!mInitialized.load()) return; + const int BUFFER_SIZE = 256; char buffer[BUFFER_SIZE]; va_list args; @@ -143,9 +172,17 @@ void LogRecorder::addMessage(const char *format, ...) vsnprintf(buffer, BUFFER_SIZE, format, args); va_end(args); - std::lock_guard lock(mMutex); - mMessages.pop_front(); - mMessages.push_back(std::string(buffer)); + if (!mIsPrinting.load()) { + std::lock_guard lock(mMutex); + + std::thread::id this_id = std::this_thread::get_id(); + if (this_id == mMainThreadId) { + if (!mMainMessages.empty()) mMainMessages.pop_back(); + mMainMessages.push_front(std::string(buffer)); + } + if (!mAllMessages.empty()) mAllMessages.pop_back(); + mAllMessages.push_front(std::string(buffer)); + } } #endif // LOG_RECORDER_ENABLED diff --git a/wakeup-manager/src/wakeup_audio_manager.cpp b/wakeup-manager/src/wakeup_audio_manager.cpp index c507c46..d79c923 100644 --- a/wakeup-manager/src/wakeup_audio_manager.cpp +++ b/wakeup-manager/src/wakeup_audio_manager.cpp @@ -11,6 +11,7 @@ #include #include +#include #include #include @@ -88,8 +89,6 @@ void recording_focus_state_watch_cb(int id, sound_stream_focus_mask_e focus_mask int CAudioManager::initialize(void) { - sound_manager_add_focus_state_watch_cb(SOUND_STREAM_FOCUS_FOR_RECORDING, - recording_focus_state_watch_cb, this, &mSoundFocusWatchId); return 0; } @@ -116,11 +115,27 @@ int CAudioManager::deinitialize(void) } } - sound_manager_remove_focus_state_watch_cb(mSoundFocusWatchId); + return 0; +} + +int CAudioManager::activate(void) +{ + MWR_LOGE("[ENTER]"); + std::cerr << "CAudioManager activation started" << std::endl; + sound_manager_add_focus_state_watch_cb(SOUND_STREAM_FOCUS_FOR_RECORDING, + recording_focus_state_watch_cb, this, &mSoundFocusWatchId); + std::cerr << "CAudioManager activation finished" << std::endl; + MWR_LOGE("[END]"); return 0; } +int CAudioManager::deactivate(void) +{ + sound_manager_remove_focus_state_watch_cb(mSoundFocusWatchId); + return 0; +} + void CAudioManager::sound_focus_changed() { sound_stream_focus_change_reason_e acquired_by; diff --git a/wakeup-manager/src/wakeup_manager.cpp b/wakeup-manager/src/wakeup_manager.cpp index 8fc6f2b..9da1763 100644 --- a/wakeup-manager/src/wakeup_manager.cpp +++ b/wakeup-manager/src/wakeup_manager.cpp @@ -149,6 +149,11 @@ bool CWakeupManager::initialize() MWR_LOGE("[ENTER]"); std::cerr << "WakeupManager Initialize" << std::endl; +#ifdef LOG_RECORDER_ENABLED + LogRecorder::getInstance().initialize(); + mPeriodicLogRecorderResetTimer = ecore_timer_add(1.0f, periodic_log_recorder_reset, nullptr); +#endif // LOG_RECORDER_ENABLED + mPolicyEventObserver.set_wakeup_manager(this); mEngineEventObserver.set_wakeup_manager(this); mAudioEventObserver.set_wakeup_manager(this); @@ -177,11 +182,6 @@ bool CWakeupManager::initialize() initialize_wakeup_policy(); start_periodic_monitor_timer(); -#ifdef LOG_RECORDER_ENABLED - LogRecorder::getInstance().initialize(); - mPeriodicLogRecorderResetTimer = ecore_timer_add(1.0f, periodic_log_recorder_reset, nullptr); -#endif // LOG_RECORDER_ENABLED - MWR_LOGD("[END]"); return true; } @@ -250,6 +250,8 @@ bool CWakeupManager::activate(void) { MWR_LOGI("[ENTER]"); + mAudioManager.activate(); + if (WAKEUP_MANAGER_STATE_INACTIVE != mWakeupManagerState) return false; @@ -281,6 +283,8 @@ bool CWakeupManager::deactivate(void) stop_streaming_previous_utterance_data(); stop_streaming_follow_up_data(); + mAudioManager.deactivate(); + MWR_LOGD("[END]"); return true; }