patrick/zephyr
1
0
Fork 0
Code Issues Pull requests Actions 7 Packages Projects Releases Wiki Activity

logging: log_output: Add optional tid formatting

Browse source 
Add option to prefix log message with thread ID or thread name.
Align tests and add test case to the log_output test.

Signed-off-by: Krzysztof Chruściński <krzysztof.chruscinski@nordicsemi.no>
This commit is contained in:
Krzysztof Chruściński 2023-08-30 14:05:12 +02:00 committed by Carles Cufí
parent 70dce83f14
commit cebd140bee
6 changed files with 73 additions and 12 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
include/zephyr/logging/log_backend_std.h
View file

@ -33,6 +33,10 @@ static inline uint32_t log_backend_std_get_flags(void)
flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
}
if (IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX)) {
flags |= LOG_OUTPUT_FLAG_THREAD;
}
return flags;
}

6
include/zephyr/logging/log_output.h
View file

@ -10,6 +10,7 @@
#include <zephyr/sys/util.h>
#include <stdarg.h>
#include <zephyr/sys/atomic.h>
#include <zephyr/kernel.h>
#ifdef __cplusplus
extern "C" {
@ -50,6 +51,9 @@ extern "C" {
*/
#define LOG_OUTPUT_FLAG_FORMAT_SYSLOG BIT(6)
/** @brief Flag thread id or name prefix. */
#define LOG_OUTPUT_FLAG_THREAD BIT(7)
/**@} */
/** @brief Supported backend logging format types for use
@ -144,6 +148,7 @@ void log_output_msg_process(const struct log_output *log_output,
* @param timestamp Timestamp.
* @param domain Domain name string. Can be NULL.
* @param source Source name string. Can be NULL.
* @param tid Thread ID.
* @param level Criticality level.
* @param package Cbprintf package with a logging message string.
* @param data Data passed to hexdump API. Can bu NULL.
@ -154,6 +159,7 @@ void log_output_process(const struct log_output *log_output,
log_timestamp_t timestamp,
const char *domain,
const char *source,
const k_tid_t tid,
uint8_t level,
const uint8_t *package,
const uint8_t *data,

22
subsys/logging/log_output.c
View file

@ -325,8 +325,10 @@ static void color_postfix(const struct log_output *output,
static int ids_print(const struct log_output *output,
bool level_on,
bool func_on,
bool thread_on,
const char *domain,
const char *source,
const k_tid_t tid,
uint32_t level)
{
int total = 0;
@ -335,6 +337,15 @@ static int ids_print(const struct log_output *output,
total += print_formatted(output, "<%s> ", severity[level]);
}
if (IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX) && thread_on) {
if (IS_ENABLED(CONFIG_THREAD_NAME)) {
total += print_formatted(output, "[%s] ",
tid == NULL ? "irq" : k_thread_name_get(tid));
} else {
total += print_formatted(output, "[%p] ", tid);
}
}
if (domain) {
total += print_formatted(output, "%s/", domain);
}
@ -430,6 +441,7 @@ static uint32_t prefix_print(const struct log_output *output,
log_timestamp_t timestamp,
const char *domain,
const char *source,
const k_tid_t tid,
uint8_t level)
{
__ASSERT_NO_MSG(level <= LOG_LEVEL_DBG);
@ -438,6 +450,8 @@ static uint32_t prefix_print(const struct log_output *output,
bool stamp = flags & LOG_OUTPUT_FLAG_TIMESTAMP;
bool colors_on = flags & LOG_OUTPUT_FLAG_COLORS;
bool level_on = flags & LOG_OUTPUT_FLAG_LEVEL;
bool thread_on = IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX) &&
(flags & LOG_OUTPUT_FLAG_THREAD);
const char *tag = IS_ENABLED(CONFIG_LOG) ? z_log_get_tag() : NULL;
if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
@ -475,7 +489,7 @@ static uint32_t prefix_print(const struct log_output *output,
color_prefix(output, colors_on, level);
}
length += ids_print(output, level_on, func_on, domain, source, level);
length += ids_print(output, level_on, func_on, thread_on, domain, source, tid, level);
return length;
}
@ -492,6 +506,7 @@ void log_output_process(const struct log_output *output,
log_timestamp_t timestamp,
const char *domain,
const char *source,
const k_tid_t tid,
uint8_t level,
const uint8_t *package,
const uint8_t *data,
@ -503,7 +518,8 @@ void log_output_process(const struct log_output *output,
cbprintf_cb cb;
if (!raw_string) {
prefix_offset = prefix_print(output, flags, 0, timestamp, domain, source, level);
prefix_offset = prefix_print(output, flags, 0, timestamp,
domain, source, tid, level);
cb = out_func;
} else {
prefix_offset = 0;
@ -560,7 +576,7 @@ void log_output_msg_process(const struct log_output *output,
uint8_t *package = log_msg_get_package(msg, &plen);
uint8_t *data = log_msg_get_data(msg, &dlen);
log_output_process(output, timestamp, NULL, sname, level,
log_output_process(output, timestamp, NULL, sname, (k_tid_t)log_msg_get_tid(msg), level,
plen > 0 ? package : NULL, data, dlen, flags);
}

45
tests/subsys/logging/log_output/src/log_output_test.c
View file

@ -54,7 +54,7 @@ ZTEST(test_log_output, test_no_flags)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 0, NULL, SNAME, LOG_LEVEL_INF, package, NULL, 0, 0);
log_output_process(&log_output, 0, NULL, SNAME, NULL, LOG_LEVEL_INF, package, NULL, 0, 0);
mock_buffer[mock_len] = '\0';
zassert_equal(strcmp(exp_str, mock_buffer), 0);
@ -69,7 +69,7 @@ ZTEST(test_log_output, test_raw)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 0, NULL, SNAME, LOG_LEVEL_INTERNAL_RAW_STRING,
log_output_process(&log_output, 0, NULL, SNAME, NULL, LOG_LEVEL_INTERNAL_RAW_STRING,
package, NULL, 0, 0);
mock_buffer[mock_len] = '\0';
@ -85,7 +85,7 @@ ZTEST(test_log_output, test_no_flags_dname)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 0, DNAME, SNAME, LOG_LEVEL_INF, package, NULL, 0, 0);
log_output_process(&log_output, 0, DNAME, SNAME, NULL, LOG_LEVEL_INF, package, NULL, 0, 0);
mock_buffer[mock_len] = '\0';
zassert_equal(strcmp(exp_str, mock_buffer), 0);
@ -101,7 +101,7 @@ ZTEST(test_log_output, test_level_flag)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 0, DNAME, SNAME, LOG_LEVEL_INF,
log_output_process(&log_output, 0, DNAME, SNAME, NULL, LOG_LEVEL_INF,
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
@ -120,7 +120,7 @@ ZTEST(test_log_output, test_ts_flag)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 0, DNAME, SNAME, LOG_LEVEL_INF,
log_output_process(&log_output, 0, DNAME, SNAME, NULL, LOG_LEVEL_INF,
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
@ -140,7 +140,7 @@ ZTEST(test_log_output, test_format_ts)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 1000000, DNAME, SNAME, LOG_LEVEL_INF,
log_output_process(&log_output, 1000000, DNAME, SNAME, NULL, LOG_LEVEL_INF,
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
@ -178,7 +178,7 @@ ZTEST(test_log_output, test_levels)
for (int i = 0; i < ARRAY_SIZE(exp_strs); i++) {
reset_mock_buffer();
log_output_process(&log_output, 0, NULL, SNAME, levels[i],
log_output_process(&log_output, 0, NULL, SNAME, NULL, levels[i],
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
@ -210,7 +210,7 @@ ZTEST(test_log_output, test_colors)
for (int i = 0; i < ARRAY_SIZE(exp_strs); i++) {
reset_mock_buffer();
log_output_process(&log_output, 0, NULL, SNAME, levels[i],
log_output_process(&log_output, 0, NULL, SNAME, NULL, levels[i],
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
@ -218,6 +218,35 @@ ZTEST(test_log_output, test_colors)
}
}
ZTEST(test_log_output, test_thread_id)
{
if (!IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX)) {
return;
}
char exp_str[256];
char package[256];
if (IS_ENABLED(CONFIG_THREAD_NAME)) {
sprintf(exp_str, "<err> [%s] src: Test\r\n", k_thread_name_get(k_current_get()));
} else {
sprintf(exp_str, "<err> [%p] src: Test\r\n", k_current_get());
}
uint32_t flags = LOG_OUTPUT_FLAG_LEVEL | LOG_OUTPUT_FLAG_THREAD;
int err;
err = cbprintf_package(package, sizeof(package), 0, "Test");
zassert_true(err > 0);
log_output_process(&log_output, 0, NULL, SNAME, k_current_get(), 1,
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';
printk("%s", mock_buffer);
zassert_equal(strcmp(exp_str, mock_buffer), 0);
}
static void before(void *notused)
{
reset_mock_buffer();

6
tests/subsys/logging/log_output/testcase.yaml
View file

@ -15,3 +15,9 @@ tests:
- logging
extra_configs:
- CONFIG_LOG_TIMESTAMP_64BIT=y
logging.log_output.thread_id:
tags:
- log_output
- logging
extra_configs:
- CONFIG_LOG_THREAD_ID_PREFIX=y

2
tests/subsys/logging/log_timestamp/src/log_timestamp_test.c
View file

@ -71,7 +71,7 @@ ZTEST(test_timestamp, test_custom_timestamp)
err = cbprintf_package(package, sizeof(package), 0, TEST_STR);
zassert_true(err > 0);
log_output_process(&log_output, 1, DNAME, SNAME, LOG_LEVEL_INF,
log_output_process(&log_output, 1, DNAME, SNAME, NULL, LOG_LEVEL_INF,
package, NULL, 0, flags);
mock_buffer[mock_len] = '\0';