michaelh/zephyr
1
0
Fork 0
Code Releases Activity

logging: Adapt logger to support both versions

Browse source 
Adapted to be able to switch between v1 and v2.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
This commit is contained in:
Krzysztof Chruscinski 2020-12-22 19:55:11 +01:00 • committed by Anas Nashif
commit f1bb20f6b4
10 changed files with 341 additions and 110 deletions
Download patch file Download diff file Expand all files Collapse all files

18
include/logging/log.h
View file

@ -252,9 +252,12 @@ extern "C" {
* @param fmt Formatted string to output.
* @param ap Variable parameters.
*/
void log_printk(const char *fmt, va_list ap);
void z_log_printk(const char *fmt, va_list ap);
static inline void log_printk(const char *fmt, va_list ap)
{
z_log_printk(fmt, ap);
}
#ifndef CONFIG_LOG_MINIMAL
/** @brief Copy transient string to a buffer from internal, logger pool.
*
* Function should be used when transient string is intended to be logged.
@ -272,14 +275,15 @@ void log_printk(const char *fmt, va_list ap);
* a buffer from the pool (see CONFIG_LOG_STRDUP_MAX_STRING). In
* some configurations, the original string pointer is returned.
*/
char *log_strdup(const char *str);
#else
char *z_log_strdup(const char *str);
static inline char *log_strdup(const char *str)
{
return (char *)str;
if (IS_ENABLED(CONFIG_LOG_MINIMAL) || IS_ENABLED(CONFIG_LOG2)) {
return (char *)str;
}
return z_log_strdup(str);
}
#endif /* CONFIG_LOG_MINIMAL */
#ifdef __cplusplus
}

14
include/logging/log_backend.h
View file

@ -7,6 +7,7 @@
#define ZEPHYR_INCLUDE_LOGGING_LOG_BACKEND_H_
#include <logging/log_msg.h>
#include <logging/log_msg2.h>
#include <stdarg.h>
#include <sys/__assert.h>
#include <sys/util.h>
@ -29,6 +30,9 @@ struct log_backend;
* @brief Logger backend API.
*/
struct log_backend_api {
void (*process)(const struct log_backend *const backend,
union log_msg2_generic *msg);
void (*put)(const struct log_backend *const backend,
struct log_msg *msg);
void (*put_sync_string)(const struct log_backend *const backend,
@ -102,6 +106,16 @@ static inline void log_backend_put(const struct log_backend *const backend,
backend->api->put(backend, msg);
}
static inline void log_backend_msg2_process(
const struct log_backend *const backend,
union log_msg2_generic *msg)
{
__ASSERT_NO_MSG(backend != NULL);
__ASSERT_NO_MSG(msg != NULL);
backend->api->process(backend, msg);
}
/**
* @brief Synchronously process log message.
*

15
include/logging/log_backend_std.h
View file

@ -21,6 +21,21 @@ extern "C" {
* @{
*/
static inline uint32_t log_backend_std_get_flags(void)
{
uint32_t flags = (LOG_OUTPUT_FLAG_LEVEL | LOG_OUTPUT_FLAG_TIMESTAMP);
if (IS_ENABLED(CONFIG_LOG_BACKEND_SHOW_COLOR)) {
flags |= LOG_OUTPUT_FLAG_COLORS;
}
if (IS_ENABLED(CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP)) {
flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
}
return flags;
}
/** @brief Put log message to a standard logger backend.
*
* @param output Log output instance.

129
include/logging/log_core.h
View file

@ -141,6 +141,7 @@ extern "C" {
(0)\
)
/**
* @brief Macro for optional injection of function name as first argument of
* formatted string. COND_CODE_0() macro is used to handle no arguments
@ -151,14 +152,22 @@ extern "C" {
* argument. In order to handle string with no arguments _LOG_Z_EVAL is
* used.
*/
#define Z_LOG_STR(...) "%s: " GET_ARG_N(1, __VA_ARGS__), \
#define Z_LOG_STR2(...) "%s: " GET_ARG_N(1, __VA_ARGS__), \
(const char *)__func__\
COND_CODE_0(NUM_VA_ARGS_LESS_1(__VA_ARGS__),\
(),\
(, GET_ARGS_LESS_N(1, __VA_ARGS__))\
)
/**
* @brief Handle optional injection of function name as the first argument.
*
* Additionally, macro is handling the empty message case.
*/
#define Z_LOG_STR(...) \
COND_CODE_0(NUM_VA_ARGS_LESS_1(_, ##__VA_ARGS__), \
("%s", (const char *)__func__), \
(Z_LOG_STR2(__VA_ARGS__)))
/******************************************************************************/
/****************** Internal macros for log frontend **************************/
@ -259,6 +268,12 @@ void z_log_minimal_printk(const char *fmt, ...);
##__VA_ARGS__); \
} while (false)
#define Z_LOG_TO_VPRINTK(_level, fmt, valist) do { \
z_log_minimal_printk("%c: ", z_log_minimal_level_to_char(_level)); \
z_log_minimal_vprintk(fmt, valist); \
z_log_minimal_printk("\n"); \
} while (false)
static inline char z_log_minimal_level_to_char(int level)
{
switch (level) {
@ -274,6 +289,9 @@ static inline char z_log_minimal_level_to_char(int level)
return '?';
}
}
#define Z_LOG_INST(_inst) COND_CODE_1(CONFIG_LOG, (_inst), NULL)
/*****************************************************************************/
/****************** Macros for standard logging ******************************/
/*****************************************************************************/
@ -292,8 +310,14 @@ static inline char z_log_minimal_level_to_char(int level)
if (!LOG_CHECK_CTX_LVL_FILTER(is_user_context, _level, filters)) { \
break; \
} \
\
Z_LOG_INTERNAL(is_user_context, _level, _source, __VA_ARGS__);\
if (IS_ENABLED(CONFIG_LOG2)) { \
int _mode; \
Z_LOG_MSG2_CREATE(!IS_ENABLED(CONFIG_USERSPACE), _mode, \
CONFIG_LOG_DOMAIN_ID, _source, _level, NULL,\
0, __VA_ARGS__); \
} else { \
Z_LOG_INTERNAL(is_user_context, _level, _source, __VA_ARGS__);\
} \
if (false) { \
/* Arguments checker present but never evaluated.*/ \
/* Placed here to ensure that __VA_ARGS__ are*/ \
@ -309,7 +333,8 @@ static inline char z_log_minimal_level_to_char(int level)
(void *)__log_current_const_data, \
__VA_ARGS__)
#define Z_LOG_INSTANCE(_level, _inst, ...) Z_LOG2(_level, _inst, __VA_ARGS__)
#define Z_LOG_INSTANCE(_level, _inst, ...) \
Z_LOG2(_level, Z_LOG_INST(_inst), __VA_ARGS__)
/*****************************************************************************/
@ -333,8 +358,19 @@ static inline char z_log_minimal_level_to_char(int level)
if (!LOG_CHECK_CTX_LVL_FILTER(is_user_context, _level, filters)) { \
break; \
} \
if (IS_ENABLED(CONFIG_LOG2)) { \
int mode; \
Z_LOG_MSG2_CREATE(!IS_ENABLED(CONFIG_USERSPACE), mode, \
CONFIG_LOG_DOMAIN_ID, _source, _level, \
_data, _len, \
COND_CODE_0(NUM_VA_ARGS_LESS_1(_, ##__VA_ARGS__), \
(), \
(COND_CODE_0(NUM_VA_ARGS_LESS_1(__VA_ARGS__), \
("%s", __VA_ARGS__), (__VA_ARGS__)))));\
break; \
} \
uint16_t src_id = \
IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ? \
IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ? \
LOG_DYNAMIC_ID_GET(_source) : LOG_CONST_ID_GET(_source);\
struct log_msg_ids src_level = { \
.level = _level, \
@ -358,7 +394,7 @@ static inline char z_log_minimal_level_to_char(int level)
_data, _length, __VA_ARGS__)
#define Z_LOG_HEXDUMP_INSTANCE(_level, _inst, _data, _length, _str) \
Z_LOG_HEXDUMP2(_level, _inst, _data, _length, _str)
Z_LOG_HEXDUMP2(_level, Z_LOG_INST(_inst), _data, _length, _str)
/*****************************************************************************/
/****************** Filtering macros *****************************************/
@ -619,6 +655,21 @@ void log_hexdump_sync(struct log_msg_ids src_level, const char *metadata,
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap,
enum log_strdup_action strdup_action);
/**
* @brief Writes a generic log message to the logging v2.
*
* @note This function is intended to be used when porting other log systems.
*
* @param level Log level..
* @param fmt String to format.
* @param ap Poiner to arguments list.
*/
static inline void log2_generic(uint8_t level, const char *fmt, va_list ap)
{
z_log_msg2_runtime_vcreate(CONFIG_LOG_DOMAIN_ID, NULL, level,
NULL, 0, fmt, ap);
}
/**
* @brief Returns number of arguments visible from format string.
*
@ -738,33 +789,45 @@ __syscall void z_log_hexdump_from_user(uint32_t src_level_val,
/********* Speed optimized for up to three arguments number. ***************/
/******************************************************************************/
#define Z_LOG_VA(_level, _str, _valist, _argnum, _strdup_action)\
__LOG_VA(_level, \
(uint16_t)LOG_CURRENT_MODULE_ID(), \
LOG_CURRENT_DYNAMIC_DATA_ADDR(), \
_str, _valist, _argnum, _strdup_action)
__LOG_VA(_level, \
IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ? \
(void *)__log_current_dynamic_data : \
(void *)__log_current_const_data, \
_str, _valist, _argnum, _strdup_action)
#define __LOG_VA(_level, _id, _filter, _str, _valist, _argnum, _strdup_action) \
do { \
if (Z_LOG_CONST_LEVEL_CHECK(_level)) { \
bool is_user_context = k_is_user_context(); \
\
if (IS_ENABLED(CONFIG_LOG_MINIMAL)) { \
z_log_minimal_printk(_str, _valist); \
} else if (LOG_CHECK_CTX_LVL_FILTER(is_user_context, \
_level, _filter)) { \
struct log_msg_ids src_level = { \
.level = _level, \
.domain_id = CONFIG_LOG_DOMAIN_ID, \
.source_id = _id \
}; \
__LOG_INTERNAL_VA(is_user_context, \
src_level, \
_str, _valist, _argnum, \
_strdup_action); \
} else { \
} \
} \
} while (false)
#define __LOG_VA(_level, _source, _str, _valist, _argnum, _strdup_action) do { \
if (!Z_LOG_CONST_LEVEL_CHECK(_level)) { \
break; \
} \
if (IS_ENABLED(CONFIG_LOG_MINIMAL)) { \
Z_LOG_TO_VPRINTK(_level, _str, _valist); \
break; \
} \
\
bool is_user_context = k_is_user_context(); \
uint32_t filters = IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ? \
((struct log_source_dynamic_data *)(void *)(_source))->filters : 0;\
if (!LOG_CHECK_CTX_LVL_FILTER(is_user_context, _level, filters)) { \
break; \
} \
if (IS_ENABLED(CONFIG_LOG2)) { \
z_log_msg2_runtime_vcreate(CONFIG_LOG_DOMAIN_ID, _source, \
_level, NULL, 0, _str, _valist); \
break; \
} \
uint16_t _id = \
IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ? \
LOG_DYNAMIC_ID_GET(_source) : LOG_CONST_ID_GET(_source);\
struct log_msg_ids src_level = { \
.level = _level, \
.domain_id = CONFIG_LOG_DOMAIN_ID, \
.source_id = _id \
}; \
__LOG_INTERNAL_VA(is_user_context, \
src_level, \
_str, _valist, _argnum, \
_strdup_action); \
} while (false)
/**
* @brief Inline function to perform strdup, used in __LOG_INTERNAL_VA macro

13
include/sys/printk.h
View file

@ -45,8 +45,21 @@ extern "C" {
* @return N/A
*/
#ifdef CONFIG_PRINTK
#if defined(CONFIG_LOG_PRINTK) && defined(CONFIG_LOG2)
#include <logging/log.h>
#define printk(...) Z_LOG_PRINTK(__VA_ARGS__)
static inline __printf_like(1, 0) void vprintk(const char *fmt, va_list ap)
{
z_log_msg2_runtime_vcreate(CONFIG_LOG_DOMAIN_ID, NULL,
LOG_LEVEL_INTERNAL_RAW_STRING, NULL, 0,
fmt, ap);
}
#else
extern __printf_like(1, 2) void printk(const char *fmt, ...);
extern __printf_like(1, 0) void vprintk(const char *fmt, va_list ap);
#endif /* defined(CONFIG_LOG_PRINTK) && defined(CONFIG_LOG) */
#else
static inline __printf_like(1, 2) void printk(const char *fmt, ...)
{

12
lib/os/printk.c
View file

@ -22,7 +22,8 @@
#include <sys/cbprintf.h>
#include <sys/types.h>
#ifdef CONFIG_PRINTK_SYNC
#if defined(CONFIG_PRINTK_SYNC) && \
!(defined(CONFIG_LOG_PRINTK) && defined(CONFIG_LOG2))
static struct k_spinlock lock;
#endif
@ -76,8 +77,8 @@ void *__printk_get_hook(void)
}
#endif /* CONFIG_PRINTK */
#ifdef CONFIG_PRINTK
#if defined(CONFIG_PRINTK) && \
!(defined(CONFIG_LOG_PRINTK) && defined(CONFIG_LOG2))
#ifdef CONFIG_USERSPACE
struct buf_out_context {
int count;
@ -204,6 +205,7 @@ static inline void z_vrfy_k_str_out(char *c, size_t n)
*
* @return N/A
*/
void printk(const char *fmt, ...)
{
va_list ap;
@ -217,7 +219,9 @@ void printk(const char *fmt, ...)
}
va_end(ap);
}
#endif /* CONFIG_PRINTK */
#endif /* defined(CONFIG_PRINTK) && \
* !(defined(CONFIG_LOG_PRINTK) && defined(CONFIG_LOG2))
*/
struct str_context {
char *str;

18
samples/subsys/logging/logger/src/ext_log_system_adapter.c
View file

@ -24,16 +24,22 @@ static const uint8_t log_level_lut[] = {
static void log_handler(enum ext_log_level level, const char *fmt, ...)
{
struct log_msg_ids src_level = {
.level = log_level_lut[level],
.domain_id = CONFIG_LOG_DOMAIN_ID,
.source_id = LOG_CURRENT_MODULE_ID()
};
va_list ap;
va_start(ap, fmt);
log_generic(src_level, fmt, ap, LOG_STRDUP_CHECK_EXEC);
if (IS_ENABLED(CONFIG_LOG2)) {
log2_generic(log_level_lut[level], fmt, ap);
} else {
struct log_msg_ids src_level = {
.level = log_level_lut[level],
.domain_id = CONFIG_LOG_DOMAIN_ID,
.source_id = LOG_CURRENT_MODULE_ID()
};
log_generic(src_level, fmt, ap, LOG_STRDUP_CHECK_EXEC);
}
va_end(ap);
}

7
subsys/logging/Kconfig.backends
View file

@ -20,6 +20,7 @@ config LOG_BACKEND_UART_SYST_ENABLE
config LOG_BACKEND_SWO
bool "Enable Serial Wire Output (SWO) backend"
depends on HAS_SWO
depends on !LOG2
help
When enabled, backend will use SWO for logging.
@ -51,6 +52,7 @@ endif # LOG_BACKEND_SWO
config LOG_BACKEND_RTT
bool "Enable Segger J-Link RTT backend"
depends on USE_SEGGER_RTT
depends on !LOG2
default y if !SHELL_BACKEND_RTT
help
When enabled, backend will use RTT for logging. This backend works on a per
@ -152,6 +154,7 @@ config LOG_BACKEND_SPINEL
bool "Enable OpenThread dedicated Spinel protocol backend"
depends on (OPENTHREAD_COPROCESSOR_SPINEL_ON_UART_DEV_NAME!=UART_CONSOLE_ON_DEV_NAME || !LOG_BACKEND_UART)
depends on NET_L2_OPENTHREAD
depends on !LOG2
help
When enabled, backend will use OpenThread dedicated SPINEL protocol for logging.
This protocol is byte oriented and wrapps given messages into serial frames.
@ -171,12 +174,14 @@ endif # LOG_BACKEND_SPINEL
config LOG_BACKEND_NATIVE_POSIX
bool "Enable native backend"
depends on ARCH_POSIX
depends on !LOG2
help
Enable backend in native_posix
config LOG_BACKEND_XTENSA_SIM
bool "Enable xtensa simulator backend"
depends on SOC_XTENSA_SAMPLE_CONTROLLER || SOC_FAMILY_INTEL_ADSP
depends on !LOG2
help
Enable backend in xtensa simulator
@ -192,6 +197,7 @@ config LOG_BACKEND_XTENSA_OUTPUT_BUFFER_SIZE
# rsyslog message to be malformed.
config LOG_BACKEND_NET
bool "Enable networking backend"
depends on !LOG2
depends on NETWORKING && NET_UDP && !LOG_IMMEDIATE
select NET_CONTEXT_NET_PKT_POOL
help
@ -256,6 +262,7 @@ endif # LOG_BACKEND_NET
config LOG_BACKEND_ADSP
bool "Enable Intel ADSP buffer backend"
depends on SOC_FAMILY_INTEL_ADSP
depends on !LOG2
help
Enable backend for the host trace protocol of the Intel ADSP
family of audio processors

19
subsys/logging/Kconfig.mode
View file

@ -12,9 +12,22 @@ config LOG_MODE_DEFERRED
least impact on the application. Time consuming processing is
deferred to the known context.
config LOG2
config LOG2_MODE_DEFERRED
bool "Deferred logging v2"
select MPSC_PBUF
select LOG2
config LOG2_MODE_IMMEDIATE
bool "Synchronous v2"
select LOG2
select MPSC_PBUF
help
When enabled log is processed in the context of the call. It impacts
performance of the system since time consuming operations are
performed in the context of the log entry (e.g. high priority
interrupt).Logger backends must support exclusive access to work
flawlessly in that mode because one log operation can be interrupted
by another one in the higher priority context.
config LOG_MODE_IMMEDIATE
bool "Synchronous"
@ -48,9 +61,13 @@ config LOG_FRONTEND
endchoice
config LOG2
bool
config LOG_IMMEDIATE
bool
default y if LOG_MODE_IMMEDIATE
default y if LOG2_MODE_IMMEDIATE
config LOG_MINIMAL
bool

206
subsys/logging/log_core.c
View file

@ -9,9 +9,11 @@
#include <logging/log_backend.h>
#include <logging/log_ctrl.h>
#include <logging/log_output.h>
#include <logging/log_msg2.h>
#include <logging/log_core2.h>
#include <sys/mpsc_pbuf.h>
#include <sys/printk.h>
#include <sys_clock.h>
#include <init.h>
#include <sys/__assert.h>
#include <sys/atomic.h>
@ -53,11 +55,20 @@ LOG_MODULE_REGISTER(log);
#define CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS 0
#endif
#ifndef CONFIG_LOG_BUFFER_SIZE
#define CONFIG_LOG_BUFFER_SIZE 4
#endif
struct log_strdup_buf {
atomic_t refcount;
char buf[CONFIG_LOG_STRDUP_MAX_STRING + 1]; /* for termination */
} __aligned(sizeof(uintptr_t));
union log_msgs {
struct log_msg *msg;
union log_msg2_generic *msg2;
};
#define LOG_STRDUP_POOL_BUFFER_SIZE \
(sizeof(struct log_strdup_buf) * CONFIG_LOG_STRDUP_BUF_COUNT)
@ -80,30 +91,29 @@ static uint32_t log_strdup_max;
static uint32_t log_strdup_longest;
static struct k_timer log_process_thread_timer;
static uint32_t dummy_timestamp(void);
log_timestamp_get_t log_timestamp_func = dummy_timestamp;
static log_timestamp_t dummy_timestamp(void);
static log_timestamp_get_t timestamp_func = dummy_timestamp;
struct mpsc_pbuf_buffer log_buffer;
static uint32_t __aligned(Z_LOG_MSG2_ALIGNMENT)
buf32[CONFIG_LOG_BUFFER_SIZE / sizeof(int)];
static void notify_drop(struct mpsc_pbuf_buffer *buffer,
union mpsc_pbuf_generic *item)
{
/* empty for now */
}
union mpsc_pbuf_generic *item);
static const struct mpsc_pbuf_buffer_config mpsc_config = {
.buf = (uint32_t *)buf32,
.size = ARRAY_SIZE(buf32),
.notify_drop = notify_drop,
.get_wlen = log_msg2_generic_get_wlen,
.flags = 0
.flags = IS_ENABLED(CONFIG_LOG_MODE_OVERFLOW) ?
MPSC_PBUF_MODE_OVERWRITE : 0
};
bool log_is_strdup(const void *buf);
static void msg_process(union log_msgs msg, bool bypass);
static uint32_t dummy_timestamp(void)
static log_timestamp_t dummy_timestamp(void)
{
return 0;
}
@ -349,7 +359,7 @@ void log_hexdump(const char *str, const void *data, uint32_t length,
}
}
void log_printk(const char *fmt, va_list ap)
void z_log_printk(const char *fmt, va_list ap)
{
if (IS_ENABLED(CONFIG_LOG_PRINTK)) {
union {
@ -419,7 +429,7 @@ void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap,
} else if (IS_ENABLED(CONFIG_LOG_IMMEDIATE) &&
(!IS_ENABLED(CONFIG_LOG_FRONTEND))) {
struct log_backend const *backend;
uint32_t timestamp = log_timestamp_func();
uint32_t timestamp = timestamp_func();
for (int i = 0; i < log_backend_count_get(); i++) {
backend = log_backend_get(i);
@ -484,7 +494,7 @@ void log_hexdump_sync(struct log_msg_ids src_level, const char *metadata,
src_level);
} else {
struct log_backend const *backend;
uint32_t timestamp = log_timestamp_func();
log_timestamp_t timestamp = timestamp_func();
for (int i = 0; i < log_backend_count_get(); i++) {
backend = log_backend_get(i);
@ -498,20 +508,42 @@ void log_hexdump_sync(struct log_msg_ids src_level, const char *metadata,
}
}
static uint32_t k_cycle_get_32_wrapper(void)
static log_timestamp_t default_get_timestamp(void)
{
/*
* The k_cycle_get_32() is a define which cannot be referenced
* by log_timestamp_func. Instead, this wrapper is used.
*/
return k_cycle_get_32();
return IS_ENABLED(CONFIG_LOG_TIMESTAMP_64BIT) ?
sys_clock_tick_get() : k_cycle_get_32();
}
static log_timestamp_t default_lf_get_timestamp(void)
{
return IS_ENABLED(CONFIG_LOG_TIMESTAMP_64BIT) ?
k_uptime_get() : k_uptime_get_32();
}
void log_core_init(void)
{
uint32_t freq;
if (!IS_ENABLED(CONFIG_LOG_IMMEDIATE)) {
/* Set default timestamp. */
if (sys_clock_hw_cycles_per_sec() > 1000000) {
timestamp_func = default_lf_get_timestamp;
freq = 1000U;
} else {
timestamp_func = default_get_timestamp;
freq = sys_clock_hw_cycles_per_sec();
}
log_output_timestamp_freq_set(freq);
if (IS_ENABLED(CONFIG_LOG2)) {
log_set_timestamp_func(default_get_timestamp,
IS_ENABLED(CONFIG_LOG_TIMESTAMP_64BIT) ?
CONFIG_SYS_CLOCK_TICKS_PER_SEC :
sys_clock_hw_cycles_per_sec());
if (IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED)) {
z_log_msg2_init();
}
} else if (IS_ENABLED(CONFIG_LOG_MODE_DEFERRED)) {
log_msg_pool_init();
log_list_init(&list);
@ -520,17 +552,6 @@ void log_core_init(void)
CONFIG_LOG_STRDUP_BUF_COUNT);
}
/* Set default timestamp. */
if (sys_clock_hw_cycles_per_sec() > 1000000) {
log_timestamp_func = k_uptime_get_32;
freq = 1000U;
} else {
log_timestamp_func = k_cycle_get_32_wrapper;
freq = sys_clock_hw_cycles_per_sec();
}
log_output_timestamp_freq_set(freq);
/*
* Initialize aggregated runtime filter levels (no backends are
* attached yet, so leave backend slots in each dynamic filter set
@ -609,7 +630,7 @@ int log_set_timestamp_func(log_timestamp_get_t timestamp_getter, uint32_t freq)
return -EINVAL;
}
log_timestamp_func = timestamp_getter;
timestamp_func = timestamp_getter;
log_output_timestamp_freq_set(freq);
return 0;
@ -654,46 +675,72 @@ void z_vrfy_log_panic(void)
#endif
static bool msg_filter_check(struct log_backend const *backend,
struct log_msg *msg)
union log_msgs msg)
{
if (IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING)) {
if (IS_ENABLED(CONFIG_LOG2) && !z_log_item_is_msg(msg.msg2)) {
return true;
} else if (IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING)) {
uint32_t backend_level;
uint32_t msg_level;
uint8_t level;
uint8_t domain_id;
int16_t source_id;
if (IS_ENABLED(CONFIG_LOG2)) {
struct log_msg2 *msg2 = &msg.msg2->log;
struct log_source_dynamic_data *source =
(struct log_source_dynamic_data *)
log_msg2_get_source(msg2);
backend_level = log_filter_get(backend,
log_msg_domain_id_get(msg),
log_msg_source_id_get(msg),
true /*enum RUNTIME, COMPILETIME*/);
msg_level = log_msg_level_get(msg);
level = log_msg2_get_level(msg2);
domain_id = log_msg2_get_domain(msg2);
source_id = source ? log_dynamic_source_id(source) : -1;
} else {
level = log_msg_level_get(msg.msg);
domain_id = log_msg_domain_id_get(msg.msg);
source_id = log_msg_source_id_get(msg.msg);
}
return (msg_level <= backend_level);
backend_level = log_filter_get(backend, domain_id,
source_id, true);
return (level <= backend_level);
} else {
return true;
}
}
static void msg_process(struct log_msg *msg, bool bypass)
static void msg_process(union log_msgs msg, bool bypass)
{
struct log_backend const *backend;
if (!bypass) {
if (IS_ENABLED(CONFIG_LOG_DETECT_MISSED_STRDUP) &&
if (!IS_ENABLED(CONFIG_LOG2) &&
IS_ENABLED(CONFIG_LOG_DETECT_MISSED_STRDUP) &&
!panic_mode) {
detect_missed_strdup(msg);
detect_missed_strdup(msg.msg);
}
for (int i = 0; i < log_backend_count_get(); i++) {
backend = log_backend_get(i);
if (log_backend_is_active(backend) &&
msg_filter_check(backend, msg)) {
log_backend_put(backend, msg);
if (IS_ENABLED(CONFIG_LOG2)) {
log_backend_msg2_process(backend,
msg.msg2);
} else {
log_backend_put(backend, msg.msg);
}
}
}
}
log_msg_put(msg);
if (!IS_ENABLED(CONFIG_LOG2_MODE_IMMEDIATE)) {
if (IS_ENABLED(CONFIG_LOG2)) {
z_log_msg2_free(msg.msg2);
} else {
log_msg_put(msg.msg);
}
}
}
void dropped_notify(void)
@ -709,19 +756,43 @@ void dropped_notify(void)
}
}
union log_msgs get_msg(void)
{
union log_msgs msg;
if (IS_ENABLED(CONFIG_LOG2)) {
msg.msg2 = z_log_msg2_claim();
return msg;
}
int key = irq_lock();
msg.msg = log_list_head_get(&list);
irq_unlock(key);
return msg;
}
static bool next_pending(void)
{
if (IS_ENABLED(CONFIG_LOG2)) {
return z_log_msg2_pending();
}
return (log_list_head_peek(&list) != NULL);
}
bool z_impl_log_process(bool bypass)
{
struct log_msg *msg;
union log_msgs msg;
if (!backend_attached && !bypass) {
return false;
}
unsigned int key = irq_lock();
msg = log_list_head_get(&list);
irq_unlock(key);
if (msg != NULL) {
msg = get_msg();
if (msg.msg) {
atomic_dec(&buffered_cnt);
msg_process(msg, bypass);
}
@ -730,7 +801,7 @@ bool z_impl_log_process(bool bypass)
dropped_notify();
}
return (log_list_head_peek(&list) != NULL);
return next_pending();
}
#ifdef CONFIG_USERSPACE
@ -766,7 +837,13 @@ uint32_t z_log_dropped_read_and_clear(void)
bool z_log_dropped_pending(void)
{
return dropped_cnt >= 0;
return dropped_cnt > 0;
}
static void notify_drop(struct mpsc_pbuf_buffer *buffer,
union mpsc_pbuf_generic *item)
{
z_log_dropped();
}
uint32_t log_src_cnt_get(uint32_t domain_id)
@ -924,7 +1001,7 @@ uint32_t log_filter_get(struct log_backend const *const backend,
return log_compiled_level_get(source_id);
}
char *log_strdup(const char *str)
char *z_log_strdup(const char *str)
{
struct log_strdup_buf *dup;
int err;
@ -1219,9 +1296,9 @@ void z_log_msg2_init(void)
static uint32_t log_diff_timestamp(void)
{
extern log_timestamp_get_t log_timestamp_func;
extern log_timestamp_get_t timestamp_func;
return log_timestamp_func();
return timestamp_func();
}
void z_log_msg2_put_trace(struct log_msg2_trace trace)
@ -1231,7 +1308,7 @@ void z_log_msg2_put_trace(struct log_msg2_trace trace)
};
trace.hdr.timestamp = IS_ENABLED(CONFIG_LOG_TRACE_SHORT_TIMESTAMP) ?
log_diff_timestamp() : log_timestamp_func();
log_diff_timestamp() : timestamp_func();
mpsc_pbuf_put_word(&log_buffer, generic.buf);
}
@ -1242,7 +1319,7 @@ void z_log_msg2_put_trace_ptr(struct log_msg2_trace trace, void *data)
};
trace.hdr.timestamp = IS_ENABLED(CONFIG_LOG_TRACE_SHORT_TIMESTAMP) ?
log_diff_timestamp() : log_timestamp_func();
log_diff_timestamp() : timestamp_func();
mpsc_pbuf_put_word_ext(&log_buffer, generic.buf, data);
}
@ -1254,7 +1331,18 @@ struct log_msg2 *z_log_msg2_alloc(uint32_t wlen)
void z_log_msg2_commit(struct log_msg2 *msg)
{
msg->hdr.timestamp = log_timestamp_func();
msg->hdr.timestamp = timestamp_func();
if (IS_ENABLED(CONFIG_LOG2_MODE_IMMEDIATE)) {
union log_msgs msgs = {
.msg2 = (union log_msg2_generic *)msg
};
msg_process(msgs, false);
return;
}
mpsc_pbuf_commit(&log_buffer, (union mpsc_pbuf_generic *)msg);
if (IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED)) {