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

logging: enhanced external logsystems

Browse source 
Introduced interface for efficient logging from external logsystems:
Added handling of vaargs and automatic strdup to macros intended
to be used in logging interface function. Fast path to less then 4
arguments to speed up the execution. Made log_count_args external,
if external logsystem cannot count arguments.

Signed-off-by: Tomasz Konieczny <tomasz.konieczny@nordicsemi.no>
This commit is contained in:
Tomasz Konieczny 2020-03-27 08:24:53 +01:00 committed by Carles Cufí
parent 0562d9fac6
commit c73578f37a
4 changed files with 165 additions and 9 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

136
include/logging/log_core.h
View file

@ -416,6 +416,13 @@ static inline char z_log_minimal_level_to_char(int level)
extern struct log_source_const_data __log_const_start[];
extern struct log_source_const_data __log_const_end[];
/** @brief Enum with possible actions for strdup operation. */
enum log_strdup_action {
LOG_STRDUP_SKIP, /**< None RAM string duplication. */
LOG_STRDUP_EXEC, /**< Always duplicate RAM strings. */
LOG_STRDUP_CHECK_EXEC/**< Duplicate RAM strings, if not dupl. before.*/
};
/** @brief Get name of the log source.
*
* @param source_id Source ID.
@ -586,8 +593,25 @@ void log_hexdump_sync(struct log_msg_ids src_level, const char *metadata,
* @brief Writes a generic log message to the log.
*
* @note This function is intended to be used when porting other log systems.
*
* @param src_level Log identification.
* @param fmt String to format.
* @param ap Poiner to arguments list.
* @param strdup_action Manages strdup activity.
*/
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap);
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap,
enum log_strdup_action strdup_action);
/**
* @brief Returns number of arguments visible from format string.
*
* @note This function is intended to be used when porting other log systems.
*
* @param fmt Format string.
*
* @return Number of arguments.
*/
uint32_t log_count_args(const char *fmt);
/**
* @brief Writes a generic log message to the log from user mode.
@ -677,6 +701,116 @@ __syscall void z_log_hexdump_from_user(uint32_t src_level_val,
const char *metadata,
const uint8_t *data, uint32_t len);
/******************************************************************************/
/********** Mocros _VA operate on var-args parameters. ***************/
/********* Intended to be used when porting other log systems. ***************/
/********* Shall be used in the log entry interface function. ***************/
/********* 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)
#define __LOG_VA(_level, _id, _filter, _str, _valist, _argnum, _strdup_action) \
do { \
bool is_user_context = _is_user_context(); \
\
if (Z_LOG_CONST_LEVEL_CHECK(_level)) { \
if (IS_ENABLED(CONFIG_LOG_MINIMAL)) { \
if (IS_ENABLED(CONFIG_LOG_PRINTK)) { \
log_printk(_str, _valist); \
} else { \
vprintk(_str, _valist); \
} \
} else if (is_user_context || \
(_level <= LOG_RUNTIME_FILTER(_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); \
} \
} \
} while (false)
/**
* @brief Inline function to perform strdup, used in __LOG_INTERNAL_VA macro
*
* @note This function is intended to be used when porting other log systems.
*
* @param msk Bitmask marking all %s arguments.
* @param idx Index of actually processed argument.
* @param param Value of actually processed argument.
* @param action Action for strdup operation.
*
* @return Duplicated string or not changed param.
*/
static inline log_arg_t z_log_do_strdup(uint32_t msk, uint32_t idx,
log_arg_t param,
enum log_strdup_action action)
{
#ifndef CONFIG_LOG_MINIMAL
char *log_strdup(const char *str);
if (msk & (1 << idx)) {
const char *str = (const char *)param;
/* is_rodata(str) is not checked,
* because log_strdup does it.
* Hence, we will do only optional check
* if already not duplicated.
*/
if (action == LOG_STRDUP_EXEC || !log_is_strdup(str)) {
param = (log_arg_t)log_strdup(str);
}
}
#endif
return param;
}
#define __LOG_INTERNAL_VA(is_user_context, _src_level, _str, _valist, \
_argnum, _strdup_action) \
do { \
if (is_user_context) { \
log_generic_from_user(_src_level, _str, _valist); \
} else if (IS_ENABLED(CONFIG_LOG_IMMEDIATE)) { \
log_generic(_src_level, _str, _valist, _strdup_action); \
} else if (_argnum == 0) { \
_LOG_INTERNAL_0(_src_level, _str); \
} else { \
uint32_t mask = (_strdup_action != LOG_STRDUP_SKIP) ? \
z_log_get_s_mask(_str, _argnum) \
: 0; \
\
if (_argnum == 1) { \
_LOG_INTERNAL_1(_src_level, _str, \
z_log_do_strdup(mask, 0, \
va_arg(_valist, log_arg_t), _strdup_action));\
} else if (_argnum == 2) { \
_LOG_INTERNAL_2(_src_level, _str, \
z_log_do_strdup(mask, 0, \
va_arg(_valist, log_arg_t), _strdup_action), \
z_log_do_strdup(mask, 1, \
va_arg(_valist, log_arg_t), _strdup_action));\
} else if (_argnum == 3) { \
_LOG_INTERNAL_3(_src_level, _str, \
z_log_do_strdup(mask, 0, \
va_arg(_valist, log_arg_t), _strdup_action), \
z_log_do_strdup(mask, 1, \
va_arg(_valist, log_arg_t), _strdup_action), \
z_log_do_strdup(mask, 2, \
va_arg(_valist, log_arg_t), _strdup_action));\
} else { \
log_generic(_src_level, _str, _valist, _strdup_action);\
} \
} \
} while (false)
#include <syscalls/log_core.h>
#ifdef __cplusplus

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

@ -33,7 +33,7 @@ static void log_handler(enum ext_log_level level, const char *fmt, ...)
va_list ap;
va_start(ap, fmt);
log_generic(src_level, fmt, ap);
log_generic(src_level, fmt, ap, LOG_STRDUP_CHECK_EXEC);
va_end(ap);
}

3
soc/xtensa/intel_s1000/xcc/log_minimal_fixes.c
View file

@ -61,7 +61,8 @@ 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)
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap,
enum log_strdup_action strdup_action)
{
}

33
subsys/logging/log_core.c
View file

@ -335,7 +335,8 @@ void log_printk(const char *fmt, va_list ap)
z_log_string_from_user(src_level_union.value, str);
} else if (IS_ENABLED(CONFIG_LOG_IMMEDIATE)) {
log_generic(src_level_union.structure, fmt, ap);
log_generic(src_level_union.structure, fmt, ap,
LOG_STRDUP_SKIP);
} else {
uint8_t str[CONFIG_LOG_PRINTK_MAX_STRING_LENGTH + 1];
struct log_msg *msg;
@ -358,7 +359,7 @@ void log_printk(const char *fmt, va_list ap)
*
* Function counts number of '%' not followed by '%'.
*/
static uint32_t count_args(const char *fmt)
uint32_t log_count_args(const char *fmt)
{
uint32_t args = 0U;
bool prev = false; /* if previous char was a modificator. */
@ -376,11 +377,12 @@ static uint32_t count_args(const char *fmt)
return args;
}
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap)
void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap,
enum log_strdup_action strdup_action)
{
if (_is_user_context()) {
log_generic_from_user(src_level, fmt, ap);
} else if (IS_ENABLED(CONFIG_LOG_IMMEDIATE) &&
} else if (IS_ENABLED(CONFIG_LOG_IMMEDIATE) &&
(!IS_ENABLED(CONFIG_LOG_FRONTEND))) {
struct log_backend const *backend;
uint32_t timestamp = timestamp_func();
@ -395,13 +397,32 @@ void log_generic(struct log_msg_ids src_level, const char *fmt, va_list ap)
}
} else {
log_arg_t args[LOG_MAX_NARGS];
uint32_t nargs = count_args(fmt);
uint32_t nargs = log_count_args(fmt);
__ASSERT_NO_MSG(nargs < LOG_MAX_NARGS);
for (int i = 0; i < nargs; i++) {
args[i] = va_arg(ap, log_arg_t);
}
if (strdup_action != LOG_STRDUP_SKIP) {
uint32_t mask = z_log_get_s_mask(fmt, nargs);
while (mask) {
uint32_t idx = 31 - __builtin_clz(mask);
const char *str = (const char *)args[idx];
/* is_rodata(str) is not checked,
* because log_strdup does it.
* Hence, we will do only optional check
* if already not duplicated.
*/
if (strdup_action == LOG_STRDUP_EXEC
|| !log_is_strdup(str)) {
args[idx] = (log_arg_t)log_strdup(str);
}
mask &= ~BIT(idx);
}
}
log_n(fmt, args, nargs, src_level);
}
}
@ -412,7 +433,7 @@ void log_string_sync(struct log_msg_ids src_level, const char *fmt, ...)
va_start(ap, fmt);
log_generic(src_level, fmt, ap);
log_generic(src_level, fmt, ap, LOG_STRDUP_SKIP);
va_end(ap);
}