Make log recorder to store main thread messages separately 02/314602/1
authorJi-hoon Lee <dalton.lee@samsung.com>
Tue, 16 Jul 2024 02:41:15 +0000 (11:41 +0900)
committerJi-hoon Lee <dalton.lee@samsung.com>
Tue, 16 Jul 2024 02:41:15 +0000 (11:41 +0900)
Change-Id: I4d8e11562668654bf0e3dcf79bd40fa4ea089d9a

src/service_ipc_dbus.cpp
wakeup-manager/inc/log_recorder.h
wakeup-manager/inc/wakeup_audio_manager.h
wakeup-manager/src/log_recorder.cpp
wakeup-manager/src/wakeup_audio_manager.cpp
wakeup-manager/src/wakeup_manager.cpp

index fa51a915bb0a7a2dfbc5ab40d387a9c2f1db6d2d..0e30c728bdbced45c30c425df5df26076114a474 100644 (file)
@@ -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;
 }
 
index 725d2f1cbc43551ccaac85828e08932b5fc3b0f9..6f846966e5f798f65455868ffa0d75e22d7a9e5c 100644 (file)
@@ -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<std::string> mMessages;
+    std::list<std::string> mMainMessages;
+    std::list<std::string> 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};
 };
 
index b793faa23eec069e6f937e9ceffd729b7e18f502..140e5aeb35fc724c6fea0d5475e9db098d0f08cb 100644 (file)
@@ -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
index 6b37fb567ddf693fd27c8b433b67fd3cd05c3ca1..0c5c7af99eeb4270644d1571469e18d41a6baa52 100644 (file)
@@ -3,6 +3,7 @@
 #include <dlog/dlog.h>
 
 #include <fstream>
+#include <iostream>
 #include <regex>
 #include <sstream>
 
@@ -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<std::mutex> 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<std::mutex> lock(mMutex);
-    mMessages.pop_front();
-    mMessages.push_back(std::string(buffer));
+    if (!mIsPrinting.load()) {
+        std::lock_guard<std::mutex> 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
index c507c4653c3ae4a10dca016ef05a7cce95286b1e..d79c923be03013041b8380e76afb745b7e803b29 100644 (file)
@@ -11,6 +11,7 @@
 #include <sys/resource.h>
 
 #include <algorithm>
+#include <iostream>
 #include <map>
 
 #include <Ecore.h>
@@ -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;
index 8fc6f2b8b6da4fbb0a4699e91b9ccf1e047cceec..9da1763841c9987337c41647a2139adcfa4230f7 100644 (file)
@@ -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;
 }