Add log_recorder for printing last log messages on lock-up 65/307265/3
authorJi-hoon Lee <dalton.lee@samsung.com>
Tue, 5 Mar 2024 07:36:37 +0000 (16:36 +0900)
committerJi-hoon Lee <dalton.lee@samsung.com>
Wed, 6 Mar 2024 11:18:02 +0000 (20:18 +0900)
Change-Id: I463d0259014a722c0167f1c87a251e28209d325e

CMakeLists.txt
wakeup-manager/CMakeLists.txt
wakeup-manager/inc/log_recorder.h [new file with mode: 0644]
wakeup-manager/inc/wakeup_manager.h
wakeup-manager/inc/wakeup_manager_main.h
wakeup-manager/src/dependency_resolver.cpp
wakeup-manager/src/log_recorder.cpp [new file with mode: 0644]
wakeup-manager/src/wakeup_engine_manager.cpp
wakeup-manager/src/wakeup_manager.cpp

index 40b8703e60c2ab75f5ff7887bc6c4fcddeba8bfb..3a90b712122d01f6035d8341b342b3e35e2e7adc 100644 (file)
@@ -93,6 +93,7 @@ SET(SRCS
                wakeup-manager/src/dependency_resolver.cpp
                wakeup-manager/src/heap_tracer.cpp
                wakeup-manager/src/assistant_config_manager.cpp
+               wakeup-manager/src/log_recorder.cpp
 )
 ADD_EXECUTABLE(${BINNAME} ${SRCS})
 
index 03e7f1dd11502899539ce95997b27564354ec8e3..9b471fa3bfa710bea8b865a1dc39b261097f648d 100644 (file)
@@ -48,6 +48,7 @@ SET(SRCS
        src/dependency_resolver.cpp
        src/heap_tracer.cpp
        src/assistant_config_manager.cpp
+       src/log_recorder.cpp
 )
 
 FOREACH(flag ${wmpkgs_CFLAGS})
diff --git a/wakeup-manager/inc/log_recorder.h b/wakeup-manager/inc/log_recorder.h
new file mode 100644 (file)
index 0000000..725d2f1
--- /dev/null
@@ -0,0 +1,42 @@
+/* This is a log recorder that stores the last log messages not more than
+MAX_LOG_MESSAGES in a list and prints them out when main thread stalls. */
+
+#ifndef __LOG_RECORDER_H_INCLUDED__
+#define __LOG_RECORDER_H_INCLUDED__
+
+#include <atomic>
+#include <list>
+#include <mutex>
+#include <thread>
+
+//#define LOG_RECORDER_ENABLED
+
+#ifdef LOG_RECORDER_ENABLED
+
+class LogRecorder {
+public:
+    static LogRecorder& getInstance();
+
+    void initialize();
+    void deinitialize();
+
+    void resetCounter();
+    void addMessage(const char *format, ...);
+
+private:
+    LogRecorder();
+    ~LogRecorder();
+
+private:
+    const int MAX_LOG_MESSAGES = 100;
+    const int MAX_TIMER_COUNTER = 10;
+    std::mutex mMutex;
+    std::list<std::string> mMessages;
+    std::thread mPrintThread;
+    std::atomic_bool mIsRunning{false};
+    std::atomic_int mCounter{0};
+};
+
+#endif // LOG_RECORDER_ENABLED
+
+#endif // __LOG_RECORDER_H_INCLUDED__
index 994dab3c42c84c3b74a5d1b7c525b96bab858476..5027b90643489b97a7c132c87e923d3892d41485 100644 (file)
@@ -25,6 +25,7 @@
 #include "wakeup_audio_manager.h"
 #include "wakeup_policy_default.h"
 #include "assistant_config_manager.h"
+#include "log_recorder.h"
 
 #include <memory>
 #include <map>
@@ -270,6 +271,10 @@ private:
        mutex mVoiceKeyStatusUpdateMutex;
 
        mutex mMutex;
+
+#ifdef LOG_RECORDER_ENABLED
+       Ecore_Timer* mPeriodicLogRecorderResetTimer{nullptr};
+#endif // LOG_RECORDER_ENABLED
 };
 
 } // wakeup
index 57aebe32fbfb3f29e1872241b6b65f3ea692efcd..b677ca7436a498d64e5595f509ce757ef9b60c8d 100644 (file)
@@ -5,6 +5,8 @@
 #include <glib.h>
 #include <stdio.h>
 
+#include "log_recorder.h"
+
 #ifdef  LOG_TAG
 #undef  LOG_TAG
 #endif
                 __dlog_print(id, prio, tag, "%s: %s(%d) > [SECURE_LOG] " fmt, __MODULE__, __func__, __LINE__, ##arg); \
         } while (0); })
 
-#define MWR_LOG_(prio, tag, fmt, arg...) \
+#ifdef LOG_RECORDER_ENABLED
+
+#define MWR_LOG_(record_only, prio, tag, fmt, arg...) \
         ({ do { \
-                dlog_print(prio, tag, "%s: %s(%d) > " fmt, __MODULE__, __func__, __LINE__, ##arg); \
+                if (!record_only) dlog_print(prio, tag, "%s: %s(%d) > " fmt, __MODULE__, __func__, __LINE__, ##arg); \
+                LogRecorder::getInstance().addMessage("%s: %s(%d) > " fmt, __MODULE__, __func__, __LINE__, ##arg); \
         } while (0); })
+#else
+#define MWR_LOG_(record_only, prio, tag, fmt, arg...) \
+        ({ do { \
+                if (!record_only) dlog_print(prio, tag, "%s: %s(%d) > " fmt, __MODULE__, __func__, __LINE__, ##arg); \
+        } while (0); })
+#endif
 
-#define MWR_LOGD(fmt, args...) MWR_LOG_(DLOG_DEBUG, LOG_TAG, fmt, ##args)
-#define MWR_LOGI(fmt, args...) MWR_LOG_(DLOG_INFO, LOG_TAG, fmt, ##args)
-#define MWR_LOGW(fmt, args...) MWR_LOG_(DLOG_WARN, LOG_TAG, fmt, ##args)
-#define MWR_LOGE(fmt, args...) MWR_LOG_(DLOG_ERROR, LOG_TAG, fmt, ##args)
+#define MWR_LOGD(fmt, args...) MWR_LOG_(0, DLOG_DEBUG, LOG_TAG, fmt, ##args)
+#define MWR_LOGI(fmt, args...) MWR_LOG_(0, DLOG_INFO, LOG_TAG, fmt, ##args)
+#define MWR_LOGW(fmt, args...) MWR_LOG_(0, DLOG_WARN, LOG_TAG, fmt, ##args)
+#define MWR_LOGE(fmt, args...) MWR_LOG_(0, DLOG_ERROR, LOG_TAG, fmt, ##args)
+#define MWR_LOGR(fmt, args...) MWR_LOG_(1, DLOG_ERROR, LOG_TAG, fmt, ##args)
 
 #define MWR_SLOGD(fmt, args...) MWR_SECURE_LOG_(DLOG_DEBUG, LOG_TAG, fmt, ##args)
 #define MWR_SLOGI(fmt, args...) MWR_SECURE_LOG_(DLOG_INFO, LOG_TAG, fmt, ##args)
index abacd599aa89fd762839aef971fa19f36240b881..644f6d0243aaf7d2b0a546ced23e5dff65f541f4 100644 (file)
@@ -26,6 +26,7 @@
 
 #include "service_common.h"
 #include "dependency_resolver.h"
+#include "wakeup_manager_main.h"
 
 #ifdef LOG_TAG
 #undef LOG_TAG
@@ -118,6 +119,7 @@ int dependency_resolver_initialize(mas_dependency_plugin_proxy_interface interfa
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_INITIALIZE);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_intialize");
                        try {
                                ret = func(interface, &dependency_version);
                        } catch (const std::exception& e) {
@@ -127,6 +129,7 @@ int dependency_resolver_initialize(mas_dependency_plugin_proxy_interface interfa
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to initialize, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_intialize");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -144,6 +147,7 @@ int dependency_resolver_deinitialize(void)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_DEINITIALIZE);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_deintialize");
                        try {
                                ret = func();
                        } catch (const std::exception& e) {
@@ -153,6 +157,7 @@ int dependency_resolver_deinitialize(void)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to deinitialize, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_deintialize");
                }
 
                dlclose(g_handle);
@@ -172,6 +177,7 @@ int dependency_resolver_set_error_callback(mas_error_cb callback, void* user_dat
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_SET_ERROR_CALLBACK);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_set_error_callback");
                        try {
                                ret = func(callback, user_data);
                        } catch (const std::exception& e) {
@@ -181,6 +187,7 @@ int dependency_resolver_set_error_callback(mas_error_cb callback, void* user_dat
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to set error callback(%p, %p), ret(%d)", callback, user_data, ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_set_error_callback");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -197,6 +204,7 @@ int dependency_resolver_start_recording(void)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_START_RECORDING);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_start_recording");
                        try {
                                ret = func();
                        } catch (const std::exception& e) {
@@ -206,6 +214,7 @@ int dependency_resolver_start_recording(void)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to start recording, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_start_recording");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -222,6 +231,7 @@ int dependency_resolver_stop_recording(void)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_STOP_RECORDING);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_stop_recording");
                        try {
                                ret = func();
                        } catch (const std::exception& e) {
@@ -231,6 +241,7 @@ int dependency_resolver_stop_recording(void)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to stop recording, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_stop_recording");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -248,6 +259,7 @@ int dependency_resolver_set_recording_session(unsigned int session)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_SET_RECORDING_SESSION);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_set_recording_session");
                        try {
                                ret = func(session);
                        } catch (const std::exception& e) {
@@ -257,6 +269,7 @@ int dependency_resolver_set_recording_session(unsigned int session)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to set recording session, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_set_recording_session");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -273,6 +286,7 @@ int dependency_resolver_set_background_volume(double ratio)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_SET_BACKGROUND_VOLUME);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_set_background_volume");
                        try {
                                ret = func(ratio);
                        } catch (const std::exception& e) {
@@ -282,6 +296,7 @@ int dependency_resolver_set_background_volume(double ratio)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to set background volume to %f, ret(%d)", ratio, ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_set_background_volume");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -298,6 +313,7 @@ int dependency_resolver_get_audio_format(int* rate, int* channel, int* audio_typ
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_GET_AUDIO_FORMAT);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_get_audio_format");
                        try {
                                ret = func(rate, channel, audio_type);
                        } catch (const std::exception& e) {
@@ -307,6 +323,7 @@ int dependency_resolver_get_audio_format(int* rate, int* channel, int* audio_typ
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to get audio format, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_get_audio_format");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -323,6 +340,7 @@ int dependency_resolver_get_audio_source_type(char** type)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_GET_AUDIO_SOURCE_TYPE);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_get_audio_source_type");
                        try {
                                ret = func(type);
                        } catch (const std::exception& e) {
@@ -332,6 +350,7 @@ int dependency_resolver_get_audio_source_type(char** type)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to get audio source type, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_get_audio_source_type");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -348,6 +367,7 @@ int dependency_resolver_process_wakeup_engine_command(const char* engine, const
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_PROCESS_WAKEUP_ENGINE_COMMAND);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_process_wakeup_engine_command");
                        try {
                                ret = func(engine, command);
                        } catch (const std::exception& e) {
@@ -357,6 +377,7 @@ int dependency_resolver_process_wakeup_engine_command(const char* engine, const
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to process wakeup engine command, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_process_wakeup_engine_command");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -373,6 +394,7 @@ int dependency_resolver_process_wakeup_candidate(mas_wakeup_event_info* info)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_PROCESS_WAKEUP_CANDIDATE);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_process_wakeup_candidate");
                        try {
                                ret = func(info);
                        } catch (const std::exception& e) {
@@ -382,6 +404,7 @@ int dependency_resolver_process_wakeup_candidate(mas_wakeup_event_info* info)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to process wakeup candidate, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_process_wakeup_candidate");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -398,6 +421,7 @@ int dependency_resolver_set_voice_key_tap_duration(float duration)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_SET_VOICE_KEY_TAP_DURATION);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_set_voice_key_tap_duration");
                        try {
                                ret = func(duration);
                        } catch (const std::exception& e) {
@@ -407,6 +431,7 @@ int dependency_resolver_set_voice_key_tap_duration(float duration)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to set voice key tap duration to %f, ret(%d)", duration, ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_set_voice_key_tap_duration");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -423,6 +448,7 @@ int dependency_resolver_unset_voice_key_tap_duration()
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_UNSET_VOICE_KEY_TAP_DURATION);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_unset_voice_key_tap_duration");
                        try {
                                ret = func();
                        } catch (const std::exception& e) {
@@ -432,6 +458,7 @@ int dependency_resolver_unset_voice_key_tap_duration()
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to unset voice key tap duration, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_unset_voice_key_tap_duration");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -448,6 +475,7 @@ int dependency_resolver_set_voice_key_support_mode(const char* support_mode)
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_SET_VOICE_KEY_SUPPORT_MODE);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_set_voice_key_support_mode");
                        try {
                                ret = func(support_mode);
                        } catch (const std::exception& e) {
@@ -457,6 +485,7 @@ int dependency_resolver_set_voice_key_support_mode(const char* support_mode)
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to unset voice key tap duration, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_set_voice_key_support_mode");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
@@ -473,6 +502,7 @@ int dependency_resolver_get_custom_vconf_key(const char* default_key, char** cus
                if (NULL == func) {
                        MAS_LOGE("[ERROR] symbol lookup failed : %s", MAS_DEPENDENCY_FUNC_GET_CUSTOM_VCONF_KEY);
                } else {
+                       MWR_LOGR("[BEGIN] mas_dependency_get_custom_vconf_key");
                        try {
                                ret = func(default_key, custom_key);
                        } catch (const std::exception& e) {
@@ -482,6 +512,7 @@ int dependency_resolver_get_custom_vconf_key(const char* default_key, char** cus
                        if (0 != ret) {
                                MAS_LOGE("[ERROR] Fail to get custom vconf key, ret(%d)", ret);
                        }
+                       MWR_LOGR("[END] mas_dependency_get_custom_vconf_key");
                }
        } else {
                MAS_LOGE("[ERROR] g_handle is not valid");
diff --git a/wakeup-manager/src/log_recorder.cpp b/wakeup-manager/src/log_recorder.cpp
new file mode 100644 (file)
index 0000000..6b37fb5
--- /dev/null
@@ -0,0 +1,151 @@
+#include "log_recorder.h"
+
+#include <dlog/dlog.h>
+
+#include <fstream>
+#include <regex>
+#include <sstream>
+
+#include "service_common.h"
+
+#ifdef LOG_RECORDER_ENABLED
+
+LogRecorder& LogRecorder::getInstance()
+{
+    static LogRecorder instance;
+    return instance;
+}
+
+LogRecorder::LogRecorder()
+{
+    mMessages.assign(MAX_LOG_MESSAGES, std::string());
+}
+
+LogRecorder::~LogRecorder()
+{
+}
+
+static void print_esp_eip()
+{
+    std::vector<long long> addresses;
+    long long value = 0;
+
+    std::string buffer;
+
+    std::ifstream statStream("/proc/self/stat");
+    if (!statStream.is_open()) {
+        dlog_print(DLOG_ERROR, LOG_TAG, "Failed to open stat file");
+    } else {
+        while (std::getline(statStream, buffer)) {
+            std::stringstream ss(buffer);
+            std::string token;
+            int i = 0;
+            while (std::getline(ss, token,' ')) {
+                value = 0;
+                try {
+                    value = std::stoll(token, nullptr, 10);
+                } catch (const std::exception& e) {
+                    dlog_print(DLOG_ERROR, LOG_TAG, "Exception caught : %s", e.what());
+                }
+
+                addresses.push_back(value);
+                i++;
+            }
+        }
+    }
+    statStream.close();
+
+    std::ifstream mapsStream("/proc/self/maps");
+    if (!mapsStream.is_open()) {
+        dlog_print(DLOG_ERROR, LOG_TAG, "Failed to open maps file");
+    } else {
+        while (std::getline(mapsStream, buffer)) {
+            std::smatch matches;
+            std::regex search_pattern("^([0-9a-f]+)-([0-9a-f]+) [rwpx-]{4} ");
+            if (std::regex_search(buffer, matches, search_pattern)) {
+                if (matches.size() > 2) {
+                    long long begin = 0;
+                    long long end = 0;
+                    try {
+                        begin = stoll(matches[1].str(), nullptr, 16);
+                        end = stoll(matches[2].str(), nullptr, 16);
+
+                        int index = 0;
+                        for (auto address : addresses) {
+                            if (address >= begin && address <= end) {
+                                dlog_print(DLOG_ERROR, LOG_TAG, "stat index %d %llx %s", index, address, buffer.c_str());
+                            }
+                            index++;
+                        }
+                    } catch (const std::exception& e) {
+                        dlog_print(DLOG_ERROR, LOG_TAG, "Exception caught : %s", e.what());
+                    }
+                }
+            }
+        }
+    }
+    mapsStream.close();
+}
+
+void LogRecorder::initialize()
+{
+    mCounter.store(0);
+    mIsRunning.store(true);
+    mPrintThread = std::thread([this]() {
+            pthread_t thread = pthread_self();
+            pthread_setname_np(thread, "log-recorder-thread");
+            int localCounter = 0;
+            while (mIsRunning.load()) {
+                std::this_thread::sleep_for(std::chrono::seconds(1));
+                mCounter.fetch_add(1);
+                if (mCounter.load() > MAX_TIMER_COUNTER) {
+                    dlog_print(DLOG_ERROR, LOG_TAG, "Counter : %d, printing recorded logs ===", mCounter.load());
+                    std::lock_guard<std::mutex> lock(mMutex);
+                    for (auto message : mMessages) {
+                        std::this_thread::sleep_for(std::chrono::milliseconds(10));
+                        dlog_print(DLOG_ERROR, LOG_TAG, "%s", message.c_str());
+                        if (mCounter <= 0) {
+                            break;
+                        }
+                    }
+                    mCounter.store(0);
+                    dlog_print(DLOG_ERROR, LOG_TAG, "Counter is now 0, printed recorded logs ===");
+
+                    print_esp_eip();
+                }
+
+                if (localCounter++ > 10) {
+                    dlog_print(DLOG_ERROR, LOG_TAG, "Log recorder is running");
+                    localCounter = 0;
+                }
+            }
+        });
+}
+
+void LogRecorder::deinitialize()
+{
+    mCounter.store(0);
+    mIsRunning.store(false);
+    mPrintThread.join();
+}
+
+void LogRecorder::resetCounter()
+{
+    mCounter.store(0);
+}
+
+void LogRecorder::addMessage(const char *format, ...)
+{
+    const int BUFFER_SIZE = 256;
+    char buffer[BUFFER_SIZE];
+    va_list args;
+    va_start(args, 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));
+}
+
+#endif // LOG_RECORDER_ENABLED
index b2c92b5fa59d1e8af90c9e33387686ff121e6dbf..ee866a9947eebfb7a1604e22de89282cb14aa5ec 100644 (file)
@@ -111,6 +111,7 @@ void CWakeupEngineManager::deinitialize()
        mStopStreamingThread.store(false);
 
        for (auto& info : mEngineInfo) {
+               MWR_LOGR("[BEGIN] engine_deinitialize : %s", info.engine_name.c_str());
                try {
                        if (info.interface.set_wakeup_event_callback) {
                                info.interface.set_wakeup_event_callback(nullptr, nullptr);
@@ -136,6 +137,7 @@ void CWakeupEngineManager::deinitialize()
                        MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                info.engine_name.c_str(), e.what());
                }
+               MWR_LOGR("[END] engine_deinitialize : %s", info.engine_name.c_str());
                if (info.engine_handle) {
                        int ret = dlclose(info.engine_handle);
                        MWR_LOGI("Closing [%s] returned %d, [%s]", info.engine_name.c_str(), ret,
@@ -189,12 +191,14 @@ bool CWakeupEngineManager::set_language(string language)
 {
        for (const auto& info : mEngineInfo) {
                if (info.interface.set_language) {
+                       MWR_LOGR("[BEGIN] engine_set_language : %s", info.engine_name.c_str());
                        try {
                                info.interface.set_language(language.c_str());
                        } catch (const std::exception& e) {
                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                        info.engine_name.c_str(), e.what());
                        }
+                       MWR_LOGR("[END] engine_set_language : %s", info.engine_name.c_str());
                }
        }
        return true;
@@ -210,6 +214,7 @@ bool CWakeupEngineManager::set_assistant_language(string appid, string language)
 
                /* If the appid is in the assistant list */
                if (info.assistant_list.end() != iter) {
+                       MWR_LOGR("[BEGIN] engine_set_assistant_language : %s", info.engine_name.c_str());
                        try {
                                int ret = info.interface.set_language(language.c_str());
                                MWR_LOGI("set_language returned %d : %s %s %s",
@@ -218,6 +223,7 @@ bool CWakeupEngineManager::set_assistant_language(string appid, string language)
                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                        info.engine_name.c_str(), e.what());
                        }
+                       MWR_LOGR("[END] engine_set_assistant_language : %s", info.engine_name.c_str());
                }
        }
        return true;
@@ -244,6 +250,7 @@ void CWakeupEngineManager::set_assistant_activated(string appid, bool activated)
                        info.activated = (info.activated_assistants.size() > 0);
                        if (previously_activated != info.activated) {
                                if (info.activated) {
+                                       MWR_LOGR("[BEGIN] engine_activate : %s", info.engine_name.c_str());
                                        try {
                                                info.interface.activate();
                                                MWR_LOGW("Activating wakeup engine : %s", info.engine_name.c_str());
@@ -251,7 +258,9 @@ void CWakeupEngineManager::set_assistant_activated(string appid, bool activated)
                                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                                        info.engine_name.c_str(), e.what());
                                        }
+                                       MWR_LOGR("[END] engine_activate : %s", info.engine_name.c_str());
                                } else {
+                                       MWR_LOGR("[BEGIN] engine_deactivate : %s", info.engine_name.c_str());
                                        try {
                                                info.interface.deactivate();
                                                MWR_LOGW("Deactivating wakeup engine : %s", info.engine_name.c_str());
@@ -259,6 +268,7 @@ void CWakeupEngineManager::set_assistant_activated(string appid, bool activated)
                                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                                        info.engine_name.c_str(), e.what());
                                        }
+                                       MWR_LOGR("[END] engine_deactivate : %s", info.engine_name.c_str());
                                }
                                /* Activated status changed, need to update audio_data_require_status too */
                                on_audio_data_require_status(info.engine_name, info.audio_data_require_status);
@@ -275,12 +285,14 @@ void CWakeupEngineManager::set_wake_word_audio_require_flag(bool require)
        mWakeWordAudioRequired = require;
        for (const auto& info : mEngineInfo) {
                if (info.interface.set_wake_word_audio_require_flag) {
+                       MWR_LOGR("[BEGIN] engine_set_wake_word_audio_require_flag : %s", info.engine_name.c_str());
                        try {
                                info.interface.set_wake_word_audio_require_flag(require);
                        } catch (const std::exception& e) {
                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                        info.engine_name.c_str(), e.what());
                        }
+                       MWR_LOGR("[END] engine_set_wake_word_audio_require_flag : %s", info.engine_name.c_str());
                }
        }
 }
@@ -552,12 +564,14 @@ void CWakeupEngineManager::update_manager_state(wakeup_manager_state_e state)
 {
        for (const auto& info : mEngineInfo) {
                if (info.interface.update_manager_state) {
+                       MWR_LOGR("[BEGIN] engine_update_manager_state : %s", info.engine_name.c_str());
                        try {
                                info.interface.update_manager_state(state);
                        } catch (const std::exception& e) {
                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                        info.engine_name.c_str(), e.what());
                        }
+                       MWR_LOGR("[END] engine_update_manager_state : %s", info.engine_name.c_str());
                }
        }
        mWakeupManagerState = state;
@@ -620,12 +634,14 @@ void CWakeupEngineManager::engine_add_wakeup_word(string appid, string wakeup_wo
                bool found = contains(info.assistant_list, appid);
                if (found) {
                        if (info.interface.add_wakeup_word) {
+                               MWR_LOGR("[BEGIN] engine_add_wakeup_word : %s", info.engine_name.c_str());
                                try {
                                        info.interface.add_wakeup_word(appid.c_str(), wakeup_word.c_str(), language.c_str());
                                } catch (const std::exception& e) {
                                        MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                                info.engine_name.c_str(), e.what());
                                }
+                               MWR_LOGR("[END] engine_add_wakeup_word : %s", info.engine_name.c_str());
                        } else {
                                MWR_LOGE("Wakeup Engine does not provide add_wakeup_word");
                        }
@@ -639,12 +655,14 @@ void CWakeupEngineManager::engine_remove_wakeup_word(string appid, string wakeup
                bool found = contains(info.assistant_list, appid);
                if (found) {
                        if (info.interface.remove_wakeup_word) {
+                               MWR_LOGR("[BEGIN] engine_remove_wakeup_word : %s", info.engine_name.c_str());
                                try {
                                        info.interface.remove_wakeup_word(appid.c_str(), wakeup_word.c_str(), language.c_str());
                                } catch (const std::exception& e) {
                                        MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                                info.engine_name.c_str(), e.what());
                                }
+                               MWR_LOGR("[END] engine_remove_wakeup_word : %s", info.engine_name.c_str());
                        } else {
                                MWR_LOGE("Wakeup Engine does not provide remove_wakeup_word");
                        }
@@ -658,12 +676,14 @@ void CWakeupEngineManager::engine_set_assistant_specific_command(string appid, s
                bool found = contains(info.assistant_list, appid);
                if (found) {
                        if (info.interface.set_assistant_specific_command) {
+                               MWR_LOGR("[BEGIN] engine_set_assistant_specific_command : %s", info.engine_name.c_str());
                                try {
                                        info.interface.set_assistant_specific_command(appid.c_str(), command.c_str());
                                } catch (const std::exception& e) {
                                        MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                                info.engine_name.c_str(), e.what());
                                }
+                               MWR_LOGR("[END] engine_set_assistant_specific_command : %s", info.engine_name.c_str());
                        }
                }
        }
@@ -684,6 +704,7 @@ void CWakeupEngineManager::engine_feed_audio_data(long time, void* data, int len
                if (info.activated &&
                        info.audio_data_require_status &&
                        info.interface.feed_audio_data) {
+                       MWR_LOGR("[BEGIN] engine_feed_audio_data : %s", info.engine_name.c_str());
                        try {
                                /* After a wakeup event, wakeup engines other than the selected one
                                   does not need to receive audio data. */
@@ -702,6 +723,7 @@ void CWakeupEngineManager::engine_feed_audio_data(long time, void* data, int len
                                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
                                        info.engine_name.c_str(), e.what());
                        }
+                       MWR_LOGR("[END] engine_feed_audio_data : %s", info.engine_name.c_str());
                }
                if (print) {
                        MWR_LOGE("Feeding audio data to %s : %d %d %p %d",
@@ -983,33 +1005,43 @@ void CWakeupEngineManager::add_engine(string name, string path)
                &callback_user_data.back());
 
        try {
+               MWR_LOGR("[BEGIN] engine_set_wakeup_event_callback : %s", info.engine_name.c_str());
                if (info.interface.set_wakeup_event_callback) {
                        info.interface.set_wakeup_event_callback(
                                [](mas_wakeup_event_info info, void* user_data) {
+                                       MWR_LOGR("[BEGIN] engine_wakeup_event_callback");
                                        MWR_LOGI("user_data : %p", user_data);
                                        CallbackUserData *data = static_cast<CallbackUserData*>(user_data);
                                        if (nullptr == data) return;
                                        if (nullptr == data->manager) return;
                                        info.wakeup_engine = data->engine_name.c_str();
                                        data->manager->on_wakeup_event(data->engine_name, info);
+                                       MWR_LOGR("[END] engine_wakeup_event_callback");
                                }, &(callback_user_data.back()));
                }
+               MWR_LOGR("[END] engine_set_wakeup_event_callback : %s", info.engine_name.c_str());
 
+               MWR_LOGR("[BEGIN] engine_set_audio_require_status_callback : %s", info.engine_name.c_str());
                if (info.interface.set_audio_data_require_status_callback) {
                        info.interface.set_audio_data_require_status_callback(
                                [](bool require, void* user_data) {
+                                       MWR_LOGR("[BEGIN] engine_audio_data_require_statuc_callback");
                                        MWR_LOGI("user_data : %p", user_data);
                                        CallbackUserData *data = static_cast<CallbackUserData*>(user_data);
                                        if (nullptr == data) return;
                                        if (nullptr == data->manager) return;
                                        data->manager->on_audio_data_require_status(data->engine_name, require);
+                                       MWR_LOGR("[END] engine_audio_data_require_statuc_callback");
                                }, &(callback_user_data.back()));
                }
+               MWR_LOGR("[END] engine_set_audio_require_status_callback : %s", info.engine_name.c_str());
 
+               MWR_LOGR("[BEGIN] engine_set_wakeup_engine_command_callback : %s", info.engine_name.c_str());
                if (info.interface.set_wakeup_engine_command_callback) {
                        info.interface.set_wakeup_engine_command_callback(
                                [](mas_wakeup_engine_command_target_e target,
                                        const char* assistant_name, const char* command, void* user_data) {
+                                       MWR_LOGR("[BEGIN] engine_wakeup_engine_command_callback");
                                        MWR_LOGI("user_data : %p", user_data);
                                        CallbackUserData* data = static_cast<CallbackUserData*>(user_data);
                                        if (nullptr == data) return;
@@ -1017,17 +1049,23 @@ void CWakeupEngineManager::add_engine(string name, string path)
                                        if (nullptr == command) return;
                                        data->manager->on_wakeup_engine_command(
                                                data->engine_name, target, (assistant_name ? assistant_name : ""), command);
+                                       MWR_LOGR("[END] engine_wakeup_engine_command_callback");
                                }, &(callback_user_data.back()));
                }
+               MWR_LOGR("[END] engine_set_wakeup_engine_command_callback : %s", info.engine_name.c_str());
 
                if (info.interface.initialize) {
+                       MWR_LOGR("[BEGIN] engine_initiazlie : %s", info.engine_name.c_str());
                        info.interface.initialize();
+                       MWR_LOGR("[END] engine_initiazlie : %s", info.engine_name.c_str());
                }
                if (info.interface.get_version) {
                        int version;
+                       MWR_LOGR("[BEGIN] engine_get_version : %s", info.engine_name.c_str());
                        if (0 == info.interface.get_version(&version)) {
                                info.version = version;
                        }
+                       MWR_LOGR("[END] engine_get_version : %s", info.engine_name.c_str());
                }
        } catch (const std::exception& e) {
                MWR_LOGE("[ERROR] wakeup engine %s threw exception : %s",
index 380075de7bd44195dd3f0bd9ff105e8eec9d526e..11f4abc5b1a5697dd84e4364f95e82b263bbff8b 100644 (file)
@@ -136,6 +136,14 @@ void CWakeupManager::initialize_wakeup_policy()
        }
 }
 
+#ifdef LOG_RECORDER_ENABLED
+static Eina_Bool periodic_log_recorder_reset(void *data)
+{
+       LogRecorder::getInstance().resetCounter();
+       return ECORE_CALLBACK_RENEW;
+}
+#endif // LOG_RECORDER_ENABLED
+
 bool CWakeupManager::initialize()
 {
        MWR_LOGE("[ENTER]");
@@ -169,6 +177,11 @@ 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;
 }
@@ -178,6 +191,15 @@ bool CWakeupManager::deinitialize()
        MWR_LOGE("[ENTER]");
        std::cerr << "WakeupManager Deinitialize" << std::endl;
 
+#ifdef LOG_RECORDER_ENABLED
+       if (mPeriodicLogRecorderResetTimer) {
+               ecore_timer_del(mPeriodicLogRecorderResetTimer);
+               mPeriodicLogRecorderResetTimer= nullptr;
+       }
+
+       LogRecorder::getInstance().deinitialize();
+#endif // LOG_RECORDER_ENABLED
+
        stop_periodic_monitor_timer();
        stop_streaming_duration_timer();