Skip to content

logging: Add a log flush operation #81360

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
kartben merged 1 commit into from
Jan 15, 2025
Merged

logging: Add a log flush operation #81360

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions include/zephyr/logging/log_ctrl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,17 @@ __syscall void log_panic(void);
*/
__syscall bool log_process(void);

/**
* @brief Process all pending log messages
*/
#ifdef CONFIG_LOG_MODE_DEFERRED
void log_flush(void);
Copy link
Contributor

@pillo79 pillo79 Nov 14, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It should be possible to define log_flush as a syscall, to allow userspace to use it as well, not necessarily with LLEXT 🙂

#else
static inline void log_flush(void)
{
}
#endif

/**
* @brief Return number of buffered log messages.
*
Expand Down
53 changes: 5 additions & 48 deletions subsys/llext/llext.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -203,60 +203,17 @@ int llext_load(struct llext_loader *ldr, const char *name, struct llext **ext,

#include <zephyr/logging/log_ctrl.h>

static void llext_log_flush(void)
{
#ifdef CONFIG_LOG_MODE_DEFERRED
extern struct k_thread logging_thread;
int cur_prio = k_thread_priority_get(k_current_get());
int log_prio = k_thread_priority_get(&logging_thread);
int target_prio;
bool adjust_cur, adjust_log;

/*
* Our goal is to raise the logger thread priority above current, but if
* current has the highest possble priority, both need to be adjusted,
* particularly if the logger thread has the lowest possible priority
*/
if (log_prio < cur_prio) {
adjust_cur = false;
adjust_log = false;
target_prio = 0;
} else if (cur_prio == K_HIGHEST_THREAD_PRIO) {
adjust_cur = true;
adjust_log = true;
target_prio = cur_prio;
k_thread_priority_set(k_current_get(), cur_prio + 1);
} else {
adjust_cur = false;
adjust_log = true;
target_prio = cur_prio - 1;
}

/* adjust logging thread priority if needed */
if (adjust_log) {
k_thread_priority_set(&logging_thread, target_prio);
}

log_thread_trigger();
k_yield();

if (adjust_log) {
k_thread_priority_set(&logging_thread, log_prio);
}
if (adjust_cur) {
k_thread_priority_set(&logging_thread, cur_prio);
}
#endif
}

int llext_unload(struct llext **ext)
{
__ASSERT(*ext, "Expected non-null extension");
struct llext *tmp = *ext;

k_mutex_lock(&llext_lock, K_FOREVER);
/* Flush pending log messages, as the deferred formatting may be referencing
* strings/args in the extension we are about to unload
*/
log_flush();

llext_log_flush();
k_mutex_lock(&llext_lock, K_FOREVER);

__ASSERT(tmp->use_count, "A valid LLEXT cannot have a zero use-count!");

Expand Down
15 changes: 15 additions & 0 deletions subsys/logging/log_core.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -992,4 +992,19 @@ static int enable_logger(void)
return 0;
}

#ifdef CONFIG_LOG_MODE_DEFERRED
void log_flush(void)
{
if (IS_ENABLED(CONFIG_LOG_PROCESS_THREAD)) {
while (log_data_pending()) {
k_sleep(K_MSEC(10));
}
k_sleep(K_MSEC(10));
} else {
while (LOG_PROCESS()) {
}
}
}
#endif

SYS_INIT(enable_logger, POST_KERNEL, CONFIG_LOG_CORE_INIT_PRIORITY);
27 changes: 7 additions & 20 deletions subsys/testsuite/ztest/src/ztest.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -934,19 +934,6 @@ static void __ztest_init_unit_test_result_for_suite(struct ztest_suite_node *sui
}
}

static void flush_log(void)
{
if (IS_ENABLED(CONFIG_LOG_PROCESS_THREAD)) {
while (log_data_pending()) {
k_sleep(K_MSEC(10));
}
k_sleep(K_MSEC(10));
} else {
while (LOG_PROCESS()) {
}
}
}

/* Show one line summary for a test suite.
*/
static void __ztest_show_suite_summary_oneline(struct ztest_suite_node *suite)
Expand Down Expand Up @@ -994,7 +981,7 @@ static void __ztest_show_suite_summary_oneline(struct ztest_suite_node *suite)
TC_RESULT_TO_STR(suite_result), passrate_major, passrate_minor,
suite->name, distinct_pass, distinct_fail, distinct_skip, distinct_total,
suite_duration_worst_ms / 1000, suite_duration_worst_ms % 1000);
flush_log();
log_flush();
}

static void __ztest_show_suite_summary_verbose(struct ztest_suite_node *suite)
Expand Down Expand Up @@ -1035,12 +1022,12 @@ static void __ztest_show_suite_summary_verbose(struct ztest_suite_node *suite)

if (flush_frequency % 3 == 0) {
/** Reduce the flush frequency a bit to speed up the output */
flush_log();
log_flush();
}
flush_frequency++;
}
TC_SUMMARY_PRINT("\n");
flush_log();
log_flush();
}

static void __ztest_show_suite_summary(void)
Expand All @@ -1051,17 +1038,17 @@ static void __ztest_show_suite_summary(void)
/* Flush the log a lot to ensure that no summary content
* is dropped if it goes through the logging subsystem.
*/
flush_log();
log_flush();
TC_SUMMARY_PRINT("\n------ TESTSUITE SUMMARY START ------\n\n");
flush_log();
log_flush();
for (struct ztest_suite_node *ptr = _ztest_suite_node_list_start;
ptr < _ztest_suite_node_list_end; ++ptr) {

__ztest_show_suite_summary_oneline(ptr);
__ztest_show_suite_summary_verbose(ptr);
}
TC_SUMMARY_PRINT("------ TESTSUITE SUMMARY END ------\n\n");
flush_log();
log_flush();
}

static int __ztest_run_test_suite(struct ztest_suite_node *ptr, const void *state, bool shuffle,
Expand Down Expand Up @@ -1474,7 +1461,7 @@ int main(void)
#ifndef CONFIG_ZTEST_SHELL
test_main();
end_report();
flush_log();
log_flush();
LOG_PANIC();
if (IS_ENABLED(CONFIG_ZTEST_RETEST_IF_PASSED)) {
static __noinit struct {
Expand Down
Loading