blob: ab73b99c481125d09d81beb30948eadfc5c4a07c [file] [log] [blame]
/*
* Copyright (c) 2022 Nordic Semiconductor ASA
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <zephyr/logging/log_frontend.h>
#include <zephyr/logging/log_internal.h>
#include <zephyr/logging/log_output_dict.h>
#include <zephyr/sys/mpsc_pbuf.h>
#include <zephyr/device.h>
#include <zephyr/drivers/uart.h>
static uint32_t dbuf[CONFIG_LOG_FRONTEND_DICT_UART_BUFFER_SIZE / sizeof(uint32_t)];
struct log_frontend_uart_pkt_hdr {
MPSC_PBUF_HDR;
uint16_t len: 12;
uint32_t noff: 2;
} __packed;
BUILD_ASSERT(sizeof(struct log_frontend_uart_pkt_hdr) == sizeof(uint16_t));
struct log_frontend_uart_generic_pkt {
struct log_frontend_uart_pkt_hdr hdr;
uint8_t data[0];
} __packed;
struct log_frontend_uart_dropped_pkt {
struct log_frontend_uart_pkt_hdr hdr;
struct log_dict_output_dropped_msg_t data;
} __packed;
struct log_frontend_uart_pkt {
struct log_frontend_uart_pkt_hdr hdr;
struct log_dict_output_normal_msg_hdr_t data_hdr;
uint8_t data[0];
} __packed;
/* Union needed to avoid warning when casting to packed structure. */
union log_frontend_pkt {
struct log_frontend_uart_generic_pkt *generic;
struct log_frontend_uart_dropped_pkt *dropped;
struct log_frontend_uart_pkt *pkt;
const union mpsc_pbuf_generic *ro_pkt;
union mpsc_pbuf_generic *rw_pkt;
};
static uint32_t get_wlen(const union mpsc_pbuf_generic *packet)
{
struct log_frontend_uart_generic_pkt *hdr = (struct log_frontend_uart_generic_pkt *)packet;
return (uint32_t)hdr->hdr.len;
}
static void notify_drop(const struct mpsc_pbuf_buffer *buffer,
const union mpsc_pbuf_generic *packet)
{
}
static const struct mpsc_pbuf_buffer_config config = {
.buf = dbuf,
.size = ARRAY_SIZE(dbuf),
.notify_drop = notify_drop,
.get_wlen = get_wlen,
.flags = 0
};
static const struct device *const dev = DEVICE_DT_GET(DT_CHOSEN(zephyr_console));
static struct mpsc_pbuf_buffer buf;
static atomic_t active_cnt; /* Counts number of buffered messages. */
static atomic_t dropped; /* Counter storing number of dropped messages to be reported. */
static atomic_t adding_drop; /* Indicates that drop report message is being added. */
static volatile bool in_panic; /* Indicates that logging is in panic state. */
static bool dropped_notify; /* Indicate that drop report message should be added. */
static void tx(void);
static atomic_val_t add_drop_msg(void);
static void timeout(struct k_timer *timer)
{
if (dropped != 0) {
dropped_notify = true;
if (add_drop_msg() == 0) {
tx();
}
}
}
K_TIMER_DEFINE(dropped_timer, timeout, NULL);
/* Attempts to get pending message and initiate UART transfer. In panic it polls
* out the message in the blocking mode.
*/
static void tx(void)
{
union log_frontend_pkt generic_pkt;
struct log_frontend_uart_generic_pkt *pkt;
if (!IS_ENABLED(CONFIG_UART_ASYNC_API) && !in_panic) {
uart_irq_tx_enable(dev);
return;
}
generic_pkt.ro_pkt = mpsc_pbuf_claim(&buf);
pkt = generic_pkt.generic;
__ASSERT_NO_MSG(pkt == NULL);
size_t len = sizeof(uint32_t) * pkt->hdr.len - pkt->hdr.noff -
sizeof(struct log_frontend_uart_pkt_hdr);
if (in_panic) {
for (int i = 0; i < len; i++) {
uart_poll_out(dev, pkt->data[i]);
}
atomic_dec(&active_cnt);
} else {
int err = uart_tx(dev, pkt->data, len, SYS_FOREVER_US);
(void)err;
__ASSERT_NO_MSG(err == 0);
}
}
/* Add drop message and reset drop message count. */
static atomic_val_t add_drop_msg(void)
{
union log_frontend_pkt generic_pkt;
struct log_frontend_uart_dropped_pkt *pkt;
size_t len = sizeof(struct log_frontend_uart_dropped_pkt);
size_t wlen = ceiling_fraction(len, sizeof(uint32_t));
if (atomic_cas(&adding_drop, 0, 1) == false) {
return 1;
}
generic_pkt.rw_pkt = mpsc_pbuf_alloc(&buf, wlen, K_NO_WAIT);
pkt = generic_pkt.dropped;
if (pkt == NULL) {
return 1;
}
dropped_notify = false;
pkt->hdr.len = wlen;
pkt->hdr.noff = sizeof(uint32_t) * wlen - len;
pkt->data.type = MSG_DROPPED_MSG;
pkt->data.num_dropped_messages = atomic_set(&dropped, 0);
mpsc_pbuf_commit(&buf, generic_pkt.rw_pkt);
return atomic_inc(&active_cnt);
}
static void uart_callback(const struct device *dev,
struct uart_event *evt,
void *user_data)
{
switch (evt->type) {
case UART_TX_DONE:
{
union log_frontend_pkt generic_pkt;
generic_pkt.generic = CONTAINER_OF(evt->data.tx.buf,
struct log_frontend_uart_generic_pkt, hdr);
mpsc_pbuf_free(&buf, generic_pkt.ro_pkt);
atomic_val_t rem_pkts = atomic_dec(&active_cnt);
if (dropped_notify) {
rem_pkts = add_drop_msg();
}
if (rem_pkts > 1) {
tx();
}
}
break;
case UART_TX_ABORTED:
break;
default:
break;
}
}
static void uart_isr_callback(const struct device *dev, void *user_data)
{
static size_t curr_offset;
static union log_frontend_pkt isr_pkt;
if (uart_irq_update(dev) && uart_irq_tx_ready(dev)) {
if (isr_pkt.ro_pkt == NULL) {
isr_pkt.ro_pkt = mpsc_pbuf_claim(&buf);
__ASSERT_NO_MSG(isr_pkt.ro_pkt != NULL);
curr_offset = 0;
}
if (isr_pkt.ro_pkt != NULL) {
struct log_frontend_uart_generic_pkt *pkt = isr_pkt.generic;
size_t len = sizeof(uint32_t) * pkt->hdr.len - pkt->hdr.noff -
sizeof(struct log_frontend_uart_pkt_hdr);
size_t rem = len - curr_offset;
if (rem > 0) {
uint8_t *d = &pkt->data[curr_offset];
curr_offset += uart_fifo_fill(dev, d, rem);
} else {
mpsc_pbuf_free(&buf, isr_pkt.ro_pkt);
isr_pkt.ro_pkt = NULL;
static struct k_spinlock lock;
k_spinlock_key_t key = k_spin_lock(&lock);
active_cnt--;
if (active_cnt == 0) {
uart_irq_tx_disable(dev);
}
k_spin_unlock(&lock, key);
}
}
}
}
static inline void hdr_fill(struct log_dict_output_normal_msg_hdr_t *hdr,
const void *source,
const struct log_msg_desc desc)
{
hdr->type = MSG_NORMAL;
hdr->domain = desc.domain;
hdr->level = desc.level;
hdr->package_len = desc.package_len;
hdr->data_len = desc.data_len;
hdr->timestamp = z_log_timestamp();
hdr->source = (source != NULL) ?
(IS_ENABLED(CONFIG_LOG_RUNTIME_FILTERING) ?
log_dynamic_source_id((void *)source) :
log_const_source_id((void *)source)) :
0U;
}
/* Handle logging message in synchronous manner, in panic mode. */
static void sync_msg(const void *source,
const struct log_msg_desc desc,
uint8_t *package, const void *data)
{
struct log_dict_output_normal_msg_hdr_t hdr;
uint8_t *datas[3] = {(uint8_t *)&hdr, package, (uint8_t *)data};
size_t len[3] = {sizeof(hdr), desc.package_len, desc.data_len};
hdr_fill(&hdr, source, desc);
for (int i = 0; i < ARRAY_SIZE(datas); i++) {
for (int j = 0; j < len[i]; j++) {
uart_poll_out(dev, datas[i][j]);
}
}
}
void log_frontend_msg(const void *source,
const struct log_msg_desc desc,
uint8_t *package, const void *data)
{
uint16_t strl[4];
struct log_msg_desc outdesc = desc;
int plen = cbprintf_package_copy(package, desc.package_len, NULL, 0,
CBPRINTF_PACKAGE_CONVERT_RW_STR,
strl, ARRAY_SIZE(strl));
size_t dlen = desc.data_len;
bool dev_ready = device_is_ready(dev);
size_t total_len = plen + dlen + sizeof(struct log_frontend_uart_pkt);
size_t total_wlen = ceiling_fraction(total_len, sizeof(uint32_t));
if (in_panic) {
sync_msg(source, desc, package, data);
}
union log_frontend_pkt generic_pkt;
struct log_frontend_uart_pkt *pkt;
generic_pkt.rw_pkt = mpsc_pbuf_alloc(&buf, total_wlen, K_NO_WAIT);
pkt = generic_pkt.pkt;
if (pkt == NULL) {
/* Dropping */
atomic_inc(&dropped);
return;
}
pkt->hdr.len = total_wlen;
pkt->hdr.noff = sizeof(uint32_t) * total_wlen - total_len;
outdesc.package_len = plen;
hdr_fill(&pkt->data_hdr, source, outdesc);
plen = cbprintf_package_copy(package, desc.package_len,
pkt->data, plen,
CBPRINTF_PACKAGE_CONVERT_RW_STR,
strl, ARRAY_SIZE(strl));
if (plen < 0) {
/* error */
}
if (dlen != 0) {
memcpy(&pkt->data[plen], data, dlen);
}
mpsc_pbuf_commit(&buf, generic_pkt.rw_pkt);
if (dev_ready && (atomic_inc(&active_cnt) == 0)) {
tx();
}
}
void log_frontend_panic(void)
{
in_panic = true;
/* Flush all data */
while (atomic_get(&active_cnt) > 0) {
tx();
/* empty */
}
}
void log_frontend_init(void)
{
int err;
if (IS_ENABLED(CONFIG_UART_ASYNC_API)) {
err = uart_callback_set(dev, uart_callback, NULL);
} else if (IS_ENABLED(CONFIG_UART_INTERRUPT_DRIVEN)) {
uart_irq_callback_user_data_set(dev, uart_isr_callback, NULL);
err = 0;
}
__ASSERT(err == 0, "Failed to set callback");
if (err < 0) {
return;
}
mpsc_pbuf_init(&buf, &config);
}
/* Cannot be started in log_frontend_init because it is called before kernel is ready. */
static int log_frontend_uart_start_timer(const struct device *unused)
{
ARG_UNUSED(unused);
k_timeout_t t = K_MSEC(CONFIG_LOG_FRONTEND_DICT_UART_DROPPED_NOTIFY_PERIOD);
k_timer_start(&dropped_timer, t, t);
return 0;
}
SYS_INIT(log_frontend_uart_start_timer, POST_KERNEL,
CONFIG_KERNEL_INIT_PRIORITY_DEFAULT);