test: logging: sync log handling with log process thread

Fix issue #27570
Waiting for the log process thread handle all the log by
k_sleep(TIMEOUT), define a reasonable TIMEOUT for all platform
is difficult. This patch sync the test thread and log process
thread by taking and giving a defined semaphore.

Signed-off-by: Meng xianglin <xianglinx.meng@intel.com>
This commit is contained in:
Meng xianglin 2020-11-02 15:36:50 +08:00 committed by Anas Nashif
commit bc52a21b90

View file

@ -20,6 +20,7 @@
#define LOG_MODULE_NAME log_test #define LOG_MODULE_NAME log_test
LOG_MODULE_REGISTER(LOG_MODULE_NAME, LOG_LEVEL_INF); LOG_MODULE_REGISTER(LOG_MODULE_NAME, LOG_LEVEL_INF);
static K_SEM_DEFINE(log_sem, 0, 1);
struct backend_cb { struct backend_cb {
/* count log messages handled by this backend */ /* count log messages handled by this backend */
@ -34,6 +35,11 @@ struct backend_cb {
uint16_t exp_severity[4]; uint16_t exp_severity[4];
/* inform put() to check domain_id of message */ /* inform put() to check domain_id of message */
bool check_domain_id; bool check_domain_id;
/* How many messages have been logged.
* used in async mode, to make sure all logs have been handled by compare
* counter with total_logs
*/
size_t total_logs;
}; };
static void put(struct log_backend const *const backend, struct log_msg *msg) static void put(struct log_backend const *const backend, struct log_msg *msg)
@ -60,6 +66,11 @@ static void put(struct log_backend const *const backend, struct log_msg *msg)
} }
cb->counter++; cb->counter++;
if (IS_ENABLED(CONFIG_LOG_PROCESS_THREAD)) {
if (cb->counter == cb->total_logs) {
k_sem_give(&log_sem);
}
}
log_msg_put(msg); log_msg_put(msg);
} }
@ -130,8 +141,8 @@ static void log_setup(bool backend2_enable)
static bool log_test_process(bool bypass) static bool log_test_process(bool bypass)
{ {
if (IS_ENABLED(CONFIG_LOG_PROCESS_THREAD)) { if (IS_ENABLED(CONFIG_LOG_PROCESS_THREAD)) {
/* a dedicate thread handle log messages, wait for 1 second */ /* waiting for all logs have been handled */
k_sleep(K_MSEC(1000)); k_sem_take(&log_sem, K_FOREVER);
return false; return false;
} else { } else {
return log_process(bypass); return log_process(bypass);
@ -152,13 +163,14 @@ static void test_log_domain_id(void)
log_setup(false); log_setup(false);
backend1_cb.check_domain_id = true; backend1_cb.check_domain_id = true;
backend1_cb.total_logs = 1;
LOG_INF("info message for domain id test"); LOG_INF("info message for domain id test");
while (log_test_process(false)) { while (log_test_process(false)) {
} }
zassert_equal(1, backend1_cb.counter, zassert_equal(backend1_cb.total_logs, backend1_cb.counter,
"Unexpected amount of messages received by the backend"); "Unexpected amount of messages received by the backend");
} }
@ -221,12 +233,13 @@ static void test_log_early_logging(void)
TC_PRINT("Activate backend with context"); TC_PRINT("Activate backend with context");
memset(&backend1_cb, 0, sizeof(backend1_cb)); memset(&backend1_cb, 0, sizeof(backend1_cb));
backend1_cb.total_logs = 3;
log_backend_enable(&backend1, &backend1_cb, LOG_LEVEL_DBG); log_backend_enable(&backend1, &backend1_cb, LOG_LEVEL_DBG);
while (log_test_process(false)) { while (log_test_process(false)) {
} }
zassert_equal(3, backend1_cb.counter, zassert_equal(backend1_cb.total_logs, backend1_cb.counter,
"Unexpected amount of messages received. %d", "Unexpected amount of messages received. %d",
backend1_cb.counter); backend1_cb.counter);
} }
@ -253,11 +266,12 @@ static void test_log_severity(void)
LOG_INF("info message"); LOG_INF("info message");
LOG_WRN("warning message"); LOG_WRN("warning message");
LOG_ERR("error message"); LOG_ERR("error message");
backend1_cb.total_logs = 3;
while (log_test_process(false)) { while (log_test_process(false)) {
} }
zassert_equal(3, backend1_cb.counter, zassert_equal(backend1_cb.total_logs, backend1_cb.counter,
"Unexpected amount of messages received by the backend."); "Unexpected amount of messages received by the backend.");
} }
@ -298,11 +312,12 @@ static void test_log_timestamping(void)
LOG_INF("test timestamp"); LOG_INF("test timestamp");
LOG_INF("test timestamp"); LOG_INF("test timestamp");
LOG_WRN("test timestamp"); LOG_WRN("test timestamp");
backend1_cb.total_logs = 3;
while (log_test_process(false)) { while (log_test_process(false)) {
} }
zassert_equal(3, zassert_equal(backend1_cb.total_logs,
backend1_cb.counter, backend1_cb.counter,
"Unexpected amount of messages received by the backend."); "Unexpected amount of messages received by the backend.");
} }