log_msg2.h

Go to the documentation of this file.

/*
 * Copyright (c) 2021 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: Apache-2.0
 */
#ifndef ZEPHYR_INCLUDE_LOGGING_LOG_MSG2_H_
#define ZEPHYR_INCLUDE_LOGGING_LOG_MSG2_H_
 
#include <logging/log_instance.h>
#include <sys/mpsc_packet.h>
#include <sys/cbprintf.h>
#include <sys/atomic.h>
#include <sys/util.h>
#include <string.h>
 
#ifdef __GNUC__
#ifndef alloca
#define alloca __builtin_alloca
#endif
#else
#include <alloca.h>
#endif
 
#ifdef __cplusplus
extern "C" {
#endif
 
#define LOG_MSG2_DEBUG 0
#define LOG_MSG2_DBG(...) IF_ENABLED(LOG_MSG2_DEBUG, (printk(__VA_ARGS__)))
 
#if CONFIG_LOG_TIMESTAMP_64BIT
typedef uint64_t log_timestamp_t;
#else
typedef uint32_t log_timestamp_t;
#endif
 
#define Z_LOG_MSG2_LOG 0
#define Z_LOG_MSG2_TRACE 1
 
#define LOG_MSG2_GENERIC_HDR \
        MPSC_PBUF_HDR;\
        uint32_t type:1
 
struct log_msg2_desc {
        LOG_MSG2_GENERIC_HDR;
        uint32_t domain:3;
        uint32_t level:3;
        uint32_t package_len:10;
        uint32_t data_len:12;
        uint32_t reserved:1;
};
 
struct log_msg2_trace_hdr {
        LOG_MSG2_GENERIC_HDR;
        uint32_t evt_id:5;
#if CONFIG_LOG_TRACE_SHORT_TIMESTAMP
        uint32_t timestamp:24;
#else
        log_timestamp_t timestamp;
#endif
};
 
union log_msg2_source {
        const struct log_source_const_data *fixed;
        struct log_source_dynamic_data *dynamic;
        void *raw;
};
 
struct log_msg2_hdr {
        struct log_msg2_desc desc;
/* Attempting to keep best alignment. When address is 64 bit and timestamp 32
 * swap the order to have 16 byte header instead of 24 byte.
 */
#if (INTPTR_MAX > INT32_MAX) && !CONFIG_LOG_TIMESTAMP_64BIT
        log_timestamp_t timestamp;
        const void *source;
#else
        const void *source;
        log_timestamp_t timestamp;
#endif
#if defined(__xtensa__) && !defined(CONFIG_LOG_TIMESTAMP_64BIT)
        /* xtensa requires that cbprintf package that follows the header is
         * aligned to 16 bytes. Adding padding when necessary.
         */
        uint32_t padding;
#endif
};
 
struct log_msg2_trace {
        struct log_msg2_trace_hdr hdr;
};
 
struct log_msg2_trace_ptr {
        struct log_msg2_trace_hdr hdr;
        void *ptr;
};
 
struct log_msg2 {
        struct log_msg2_hdr hdr;
        uint8_t data[];
};
 
struct log_msg2_generic_hdr {
        LOG_MSG2_GENERIC_HDR;
};
 
union log_msg2_generic {
        union mpsc_pbuf_generic buf;
        struct log_msg2_generic_hdr generic;
        struct log_msg2_trace trace;
        struct log_msg2_trace_ptr trace_ptr;
        struct log_msg2 log;
};
 
enum z_log_msg2_mode {
        /* Runtime mode is least efficient but supports all cases thus it is
         * threated as a fallback method when others cannot be used.
         */
        Z_LOG_MSG2_MODE_RUNTIME,
        /* Mode creates statically a string package on stack and calls a
         * function for creating a message. It takes code size than
         * Z_LOG_MSG2_MODE_ZERO_COPY but is a bit slower.
         */
        Z_LOG_MSG2_MODE_FROM_STACK,
 
        /* Mode calculates size of the message and allocates it and writes
         * directly to the message space. It is the fastest method but requires
         * more code size.
         */
        Z_LOG_MSG2_MODE_ZERO_COPY,
 
        /* Mode used when synchronous logging is enabled. */
        Z_LOG_MSG2_MODE_SYNC
};
 
#define Z_LOG_MSG_DESC_INITIALIZER(_domain_id, _level, _plen, _dlen) \
{ \
        .valid = 0, \
        .busy = 0, \
        .type = Z_LOG_MSG2_LOG, \
        .domain = _domain_id, \
        .level = _level, \
        .package_len = _plen, \
        .data_len = _dlen, \
        .reserved = 0, \
}
 
/* Messages are aligned to alignment required by cbprintf package. */
#define Z_LOG_MSG2_ALIGNMENT CBPRINTF_PACKAGE_ALIGNMENT
 
#if CONFIG_LOG2_USE_VLA
#define Z_LOG_MSG2_ON_STACK_ALLOC(ptr, len) \
        long long _ll_buf[ceiling_fraction(len, sizeof(long long))]; \
        long double _ld_buf[ceiling_fraction(len, sizeof(long double))]; \
        ptr = (sizeof(long double) == Z_LOG_MSG2_ALIGNMENT) ? \
                        (struct log_msg2 *)_ld_buf : (struct log_msg2 *)_ll_buf; \
        if (IS_ENABLED(CONFIG_LOG_TEST_CLEAR_MESSAGE_SPACE)) { \
                /* During test fill with 0's to simplify message comparison */ \
                memset(ptr, 0, len); \
        }
#else /* Z_LOG_MSG2_USE_VLA */
/* When VLA cannot be used we need to trick compiler a bit and create multiple
 * fixed size arrays and take the smallest one that will fit the message.
 * Compiler will remove unused arrays and stack usage will be kept similar
 * to vla case, rounded to the size of the used buffer.
 */
#define Z_LOG_MSG2_ON_STACK_ALLOC(ptr, len) \
        long long _ll_buf32[32 / sizeof(long long)]; \
        long long _ll_buf48[48 / sizeof(long long)]; \
        long long _ll_buf64[64 / sizeof(long long)]; \
        long long _ll_buf128[128 / sizeof(long long)]; \
        long long _ll_buf256[256 / sizeof(long long)]; \
        long double _ld_buf32[32 / sizeof(long double)]; \
        long double _ld_buf48[48 / sizeof(long double)]; \
        long double _ld_buf64[64 / sizeof(long double)]; \
        long double _ld_buf128[128 / sizeof(long double)]; \
        long double _ld_buf256[256 / sizeof(long double)]; \
        if (sizeof(long double) == Z_LOG_MSG2_ALIGNMENT) { \
                ptr = (len > 128) ? (struct log_msg2 *)_ld_buf256 : \
                        ((len > 64) ? (struct log_msg2 *)_ld_buf128 : \
                        ((len > 48) ? (struct log_msg2 *)_ld_buf64 : \
                        ((len > 32) ? (struct log_msg2 *)_ld_buf48 : \
                                      (struct log_msg2 *)_ld_buf32)));\
        } else { \
                ptr = (len > 128) ? (struct log_msg2 *)_ll_buf256 : \
                        ((len > 64) ? (struct log_msg2 *)_ll_buf128 : \
                        ((len > 48) ? (struct log_msg2 *)_ll_buf64 : \
                        ((len > 32) ? (struct log_msg2 *)_ll_buf48 : \
                                      (struct log_msg2 *)_ll_buf32)));\
        } \
        if (IS_ENABLED(CONFIG_LOG_TEST_CLEAR_MESSAGE_SPACE)) { \
                /* During test fill with 0's to simplify message comparison */ \
                memset(ptr, 0, len); \
        }
#endif /* Z_LOG_MSG2_USE_VLA */
 
#define Z_LOG_MSG2_ALIGN_OFFSET \
        sizeof(struct log_msg2_hdr)
 
#define Z_LOG_MSG2_LEN(pkg_len, data_len) \
        (sizeof(struct log_msg2_hdr) + pkg_len + (data_len))
 
#define Z_LOG_MSG2_ALIGNED_WLEN(pkg_len, data_len) \
        ceiling_fraction(ROUND_UP(Z_LOG_MSG2_LEN(pkg_len, data_len), \
                                  Z_LOG_MSG2_ALIGNMENT), \
                         sizeof(uint32_t))
 
#define Z_LOG_MSG2_SYNC(_domain_id, _source, _level, _data, _dlen, ...) do { \
        int _plen; \
        CBPRINTF_STATIC_PACKAGE(NULL, 0, _plen, Z_LOG_MSG2_ALIGN_OFFSET, \
                                0, __VA_ARGS__); \
        struct log_msg2 *_msg; \
        Z_LOG_MSG2_ON_STACK_ALLOC(_msg, Z_LOG_MSG2_LEN(_plen, _dlen)); \
        if (_plen) {\
                CBPRINTF_STATIC_PACKAGE(_msg->data, _plen, _plen, \
                                        Z_LOG_MSG2_ALIGN_OFFSET, \
                                        0, __VA_ARGS__); \
        } \
        struct log_msg2_desc _desc = \
                     Z_LOG_MSG_DESC_INITIALIZER(_domain_id, _level, \
                           (uint32_t)_plen, _dlen); \
        z_log_msg2_finalize(_msg, _source, _desc, _data); \
} while (0)
 
#define Z_LOG_MSG2_STACK_CREATE(_domain_id, _source, _level, _data, _dlen, ...)\
do { \
        int _plen; \
        if (GET_ARG_N(1, __VA_ARGS__) == NULL) { \
                _plen = 0; \
        } else { \
                CBPRINTF_STATIC_PACKAGE(NULL, 0, _plen, Z_LOG_MSG2_ALIGN_OFFSET, \
                                        0, __VA_ARGS__); \
        } \
        struct log_msg2 *_msg; \
        Z_LOG_MSG2_ON_STACK_ALLOC(_msg, Z_LOG_MSG2_LEN(_plen, 0)); \
        if (_plen) { \
                CBPRINTF_STATIC_PACKAGE(_msg->data, _plen, \
                                        _plen, Z_LOG_MSG2_ALIGN_OFFSET, \
                                        0, __VA_ARGS__);\
        } \
        struct log_msg2_desc _desc = \
                Z_LOG_MSG_DESC_INITIALIZER(_domain_id, _level, \
                                           (uint32_t)_plen, _dlen); \
        LOG_MSG2_DBG("creating message on stack: package len: %d, data len: %d\n", \
                        _plen, (int)(_dlen)); \
        z_log_msg2_static_create((void *)_source, _desc, _msg->data, _data); \
} while (0)
 
#if CONFIG_LOG_SPEED
#define Z_LOG_MSG2_SIMPLE_CREATE(_domain_id, _source, _level, ...) do { \
        int _plen; \
        CBPRINTF_STATIC_PACKAGE(NULL, 0, _plen, Z_LOG_MSG2_ALIGN_OFFSET, \
                                0, __VA_ARGS__); \
        size_t _msg_wlen = Z_LOG_MSG2_ALIGNED_WLEN(_plen, 0); \
        struct log_msg2 *_msg = z_log_msg2_alloc(_msg_wlen); \
        struct log_msg2_desc _desc = \
                Z_LOG_MSG_DESC_INITIALIZER(_domain_id, _level, (uint32_t)_plen, 0); \
        LOG_MSG2_DBG("creating message zero copy: package len: %d, msg: %p\n", \
                        _plen, _msg); \
        if (_msg) { \
                CBPRINTF_STATIC_PACKAGE(_msg->data, _plen, _plen, \
                                        Z_LOG_MSG2_ALIGN_OFFSET, \
                                        0, __VA_ARGS__); \
        } \
        z_log_msg2_finalize(_msg, (void *)_source, _desc, NULL); \
} while (0)
#else
/* Alternative empty macro created to speed up compilation when LOG_SPEED is
 * disabled (default).
 */
#define Z_LOG_MSG2_SIMPLE_CREATE(...)
#endif
 
/* Macro handles case when local variable with log message string is created.It
 * replaces origing string literal with that variable.
 */
#define Z_LOG_FMT_ARGS_2(_name, ...) \
        COND_CODE_1(CONFIG_LOG2_FMT_SECTION, \
                (COND_CODE_0(NUM_VA_ARGS_LESS_1(__VA_ARGS__), \
                   (_name), (_name, GET_ARGS_LESS_N(1, __VA_ARGS__)))), \
                (__VA_ARGS__))
 
#define Z_LOG_FMT_ARGS(_name, ...) \
        COND_CODE_0(NUM_VA_ARGS_LESS_1(_, ##__VA_ARGS__), \
                (NULL), \
                (Z_LOG_FMT_ARGS_2(_name, ##__VA_ARGS__)))
 
/* Macro handles case when there is no string provided, in that case variable
 * is not created.
 */
#define Z_LOG_MSG2_STR_VAR_IN_SECTION(_name, ...) \
        COND_CODE_0(NUM_VA_ARGS_LESS_1(_, ##__VA_ARGS__), \
                    (/* No args provided, no variable */), \
                    (static const char _name[] \
                        __attribute__((__section__(".log_strings"))) = \
                        GET_ARG_N(1, __VA_ARGS__);))
 
#define Z_LOG_MSG2_STR_VAR(_name, ...) \
        IF_ENABLED(CONFIG_LOG2_FMT_SECTION, \
                   (Z_LOG_MSG2_STR_VAR_IN_SECTION(_name, ##__VA_ARGS__)))
 
#if CONFIG_LOG2_ALWAYS_RUNTIME
#define Z_LOG_MSG2_CREATE2(_try_0cpy, _mode,  _cstr_cnt, _domain_id, _source,\
                          _level, _data, _dlen, ...) \
do {\
        Z_LOG_MSG2_STR_VAR(_fmt, ##__VA_ARGS__) \
        z_log_msg2_runtime_create(_domain_id, (void *)_source, \
                                  _level, (uint8_t *)_data, _dlen,\
                                  Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__));\
        _mode = Z_LOG_MSG2_MODE_RUNTIME; \
} while (0)
#elif CONFIG_LOG2_MODE_IMMEDIATE /* CONFIG_LOG2_ALWAYS_RUNTIME */
#define Z_LOG_MSG2_CREATE2(_try_0cpy, _mode,  _cstr_cnt, _domain_id, _source,\
                          _level, _data, _dlen, ...) \
do { \
        Z_LOG_MSG2_STR_VAR(_fmt, ##__VA_ARGS__); \
        if (CBPRINTF_MUST_RUNTIME_PACKAGE(_cstr_cnt, __VA_ARGS__)) { \
                LOG_MSG2_DBG("create runtime message\n");\
                z_log_msg2_runtime_create(_domain_id, (void *)_source, \
                                          _level, (uint8_t *)_data, _dlen,\
                                          Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__));\
                _mode = Z_LOG_MSG2_MODE_RUNTIME; \
        } else {\
                Z_LOG_MSG2_SYNC(_domain_id, _source, _level, \
                                _data, _dlen, Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__)); \
                _mode = Z_LOG_MSG2_MODE_SYNC; \
        } \
} while (0)
#else /* CONFIG_LOG2_ALWAYS_RUNTIME */
#define Z_LOG_MSG2_CREATE2(_try_0cpy, _mode,  _cstr_cnt, _domain_id, _source,\
                          _level, _data, _dlen, ...) \
do { \
        Z_LOG_MSG2_STR_VAR(_fmt, ##__VA_ARGS__); \
        if (CBPRINTF_MUST_RUNTIME_PACKAGE(_cstr_cnt, __VA_ARGS__)) { \
                LOG_MSG2_DBG("create runtime message\n");\
                z_log_msg2_runtime_create(_domain_id, (void *)_source, \
                                          _level, (uint8_t *)_data, _dlen,\
                                          Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__));\
                _mode = Z_LOG_MSG2_MODE_RUNTIME; \
        } else if (IS_ENABLED(CONFIG_LOG_SPEED) && _try_0cpy && ((_dlen) == 0)) {\
                LOG_MSG2_DBG("create zero-copy message\n");\
                Z_LOG_MSG2_SIMPLE_CREATE(_domain_id, _source, \
                                        _level, Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__)); \
                _mode = Z_LOG_MSG2_MODE_ZERO_COPY; \
        } else { \
                LOG_MSG2_DBG("create on stack message\n");\
                Z_LOG_MSG2_STACK_CREATE(_domain_id, _source, _level, _data, \
                                        _dlen, Z_LOG_FMT_ARGS(_fmt, ##__VA_ARGS__)); \
                _mode = Z_LOG_MSG2_MODE_FROM_STACK; \
        } \
        (void)_mode; \
} while (0)
#endif /* CONFIG_LOG2_ALWAYS_RUNTIME */
 
#define Z_LOG_MSG2_CREATE(_try_0cpy, _mode,  _domain_id, _source,\
                          _level, _data, _dlen, ...) \
        Z_LOG_MSG2_CREATE2(_try_0cpy, _mode, UTIL_CAT(Z_LOG_FUNC_PREFIX_, _level), \
                           _domain_id, _source, _level, _data, _dlen, \
                           Z_LOG_STR(_level, __VA_ARGS__))
 
#define Z_TRACING_LOG_HDR_INIT(name, id) \
        struct log_msg2_trace name = { \
                .hdr = { \
                        .type = Z_LOG_MSG2_TRACE, \
                        .valid = 1, \
                        .busy = 0, \
                        .evt_id = id, \
                } \
        }
 
void z_log_msg2_finalize(struct log_msg2 *msg, const void *source,
                         const struct log_msg2_desc desc, const void *data);
 
__syscall void z_log_msg2_static_create(const void *source,
                                        const struct log_msg2_desc desc,
                                        uint8_t *package, const void *data);
 
__syscall void z_log_msg2_runtime_vcreate(uint8_t domain_id, const void *source,
                                          uint8_t level, const void *data,
                                          size_t dlen, const char *fmt,
                                          va_list ap);
 
static inline void z_log_msg2_runtime_create(uint8_t domain_id,
                                             const void *source,
                                             uint8_t level, const void *data,
                                             size_t dlen, const char *fmt, ...)
{
        va_list ap;
 
        va_start(ap, fmt);
        z_log_msg2_runtime_vcreate(domain_id, source, level,
                                   data, dlen, fmt, ap);
        va_end(ap);
}
 
static inline bool z_log_item_is_msg(union log_msg2_generic *msg)
{
        return msg->generic.type == Z_LOG_MSG2_LOG;
}
 
static inline uint32_t log_msg2_get_total_wlen(const struct log_msg2_desc desc)
{
        return Z_LOG_MSG2_ALIGNED_WLEN(desc.package_len, desc.data_len);
}
 
static inline uint32_t log_msg2_generic_get_wlen(union mpsc_pbuf_generic *item)
{
        union log_msg2_generic *generic_msg = (union log_msg2_generic *)item;
 
        if (z_log_item_is_msg(generic_msg)) {
                struct log_msg2 *msg = (struct log_msg2 *)generic_msg;
 
                return log_msg2_get_total_wlen(msg->hdr.desc);
        }
 
        /* trace TODO */
        return 0;
}
 
static inline uint8_t log_msg2_get_domain(struct log_msg2 *msg)
{
        return msg->hdr.desc.domain;
}
 
static inline uint8_t log_msg2_get_level(struct log_msg2 *msg)
{
        return msg->hdr.desc.level;
}
 
static inline const void *log_msg2_get_source(struct log_msg2 *msg)
{
        return msg->hdr.source;
}
 
static inline log_timestamp_t log_msg2_get_timestamp(struct log_msg2 *msg)
{
        return msg->hdr.timestamp;
}
 
static inline uint8_t *log_msg2_get_data(struct log_msg2 *msg, size_t *len)
{
        *len = msg->hdr.desc.data_len;
 
        return msg->data + msg->hdr.desc.package_len;
}
 
static inline uint8_t *log_msg2_get_package(struct log_msg2 *msg, size_t *len)
{
        *len = msg->hdr.desc.package_len;
 
        return msg->data;
}
 
#include <syscalls/log_msg2.h>
 
#ifdef __cplusplus
}
#endif
 
#endif /* ZEPHYR_INCLUDE_LOGGING_LOG_MSG2_H_ */