adafruit-mirror/zephyr
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions 9

mgmt: ec_host_cmd: add logging system

Browse source 
Add a native way to log Host Command communication.

Use Zephyr logging system to do it. Use debug and normal levels.

Signed-off-by: Dawid Niedzwiecki <dawidn@google.com>
This commit is contained in:
Dawid Niedzwiecki 2023-05-31 07:48:40 +00:00 committed by Carles Cufí
parent 159f56d57e
commit c8c149dce8
4 changed files with 75 additions and 4 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

12
doc/services/device_mgmt/ec_host_cmd.rst
View file

@ -69,6 +69,18 @@ buffers are useful for applications that use multiple backends. Defining separat
backend would increase the memory usage. However, some buffers can be defined by a peripheral driver
e.g. eSPI. These ones should be reused as much as possible.
Logging
*******
The host command has an embedded logging system of the ongoing communication. The are a few logging
levels:
* `LOG_INF` is used to log a command id of a new command and not success responses. Repeats of the
same command are not logged
* `LOG_DBG` logs every command, even repeats
* `LOG_DBG` + :kconfig:option:`CONFIG_EC_HOST_CMD_LOG_DBG_BUFFERS` logs every command and responses
with the data buffers
API Reference
*************

5
subsys/mgmt/ec_host_cmd/Kconfig
View file

@ -87,8 +87,9 @@ config EC_HOST_CMD_DEDICATED_THREAD
The ec_host_cmd_init function creates a new thread dedicated for Host Command.
Otherwise the ec_host_cmd_task function has to be called within another thread.
endif # EC_HOST_CMD
source "subsys/mgmt/ec_host_cmd/Kconfig.logging"
source "subsys/mgmt/ec_host_cmd/backends/Kconfig"
endif # EC_HOST_CMD
endmenu

12
subsys/mgmt/ec_host_cmd/Kconfig.logging Normal file
View file

@ -0,0 +1,12 @@
# Host command logging configs
# Copyright (c) 2023 Google LLC
# SPDX-License-Identifier: Apache-2.0
config EC_HOST_CMD_LOG_DBG_BUFFERS
bool "Log full params and response buffers in debug log level"
depends on EC_HC_LOG_LEVEL_DBG
help
Every command is logged with the debug logging level. Use this config
to decide, if full reqest and response buffers are logged alongside
other command parameters.

50
subsys/mgmt/ec_host_cmd/ec_host_cmd_handler.c
View file

@ -10,6 +10,7 @@
#include <zephyr/mgmt/ec_host_cmd/ec_host_cmd.h>
#include <zephyr/mgmt/ec_host_cmd/backend.h>
#include <zephyr/sys/iterable_sections.h>
#include <stdio.h>
#include <string.h>
LOG_MODULE_REGISTER(host_cmd_handler, CONFIG_EC_HC_LOG_LEVEL);
@ -161,10 +162,20 @@ int ec_host_cmd_send_response(enum ec_host_cmd_status status,
struct ec_host_cmd_tx_buf *tx = &hc->tx;
if (status != EC_HOST_CMD_SUCCESS) {
const struct ec_host_cmd_request_header *const rx_header =
(const struct ec_host_cmd_request_header *const)hc->rx_ctx.buf;
LOG_INF("HC 0x%04x err %d", rx_header->cmd_id, status);
send_status_response(hc->backend, tx, status);
return status;
}
#ifdef CONFIG_EC_HOST_CMD_LOG_DBG_BUFFERS
if (args->output_buf_size) {
LOG_HEXDUMP_DBG(args->output_buf, args->output_buf_size, "HC resp:");
}
#endif
status = prepare_response(tx, args->output_buf_size);
if (status != EC_HOST_CMD_SUCCESS) {
send_status_response(hc->backend, tx, status);
@ -174,6 +185,41 @@ int ec_host_cmd_send_response(enum ec_host_cmd_status status,
return hc->backend->api->send(hc->backend);
}
static void ec_host_cmd_log_request(const uint8_t *rx_buf)
{
static uint16_t prev_cmd;
const struct ec_host_cmd_request_header *const rx_header =
(const struct ec_host_cmd_request_header *const)rx_buf;
if (IS_ENABLED(CONFIG_EC_HOST_CMD_LOG_DBG_BUFFERS)) {
if (rx_header->data_len) {
const uint8_t *rx_data = rx_buf + RX_HEADER_SIZE;
static const char dbg_fmt[] = "HC 0x%04x.%d:";
/* Use sizeof because "%04x" needs 4 bytes for command id, and
* %d needs 2 bytes for version, so no additional buffer is required.
*/
char dbg_raw[sizeof(dbg_fmt)];
snprintf(dbg_raw, sizeof(dbg_raw), dbg_fmt, rx_header->cmd_id,
rx_header->cmd_ver);
LOG_HEXDUMP_DBG(rx_data, rx_header->data_len, dbg_raw);
return;
}
}
/* In normal output mode, skip printing repeats of the same command
* that occur in rapid succession - such as flash commands during
* software sync.
*/
if (rx_header->cmd_id != prev_cmd) {
prev_cmd = rx_header->cmd_id;
LOG_INF("HC 0x%04x", rx_header->cmd_id);
} else {
LOG_DBG("HC 0x%04x", rx_header->cmd_id);
}
}
FUNC_NORETURN static void ec_host_cmd_thread(void *hc_handle, void *arg2, void *arg3)
{
ARG_UNUSED(arg2);
@ -196,6 +242,7 @@ FUNC_NORETURN static void ec_host_cmd_thread(void *hc_handle, void *arg2, void *
/* Wait until RX messages is received on host interface */
k_sem_take(&rx->handler_owns, K_FOREVER);
ec_host_cmd_log_request(rx->buf);
status = verify_rx(rx);
if (status != EC_HOST_CMD_SUCCESS) {
ec_host_cmd_send_response(status, &args);
@ -203,8 +250,7 @@ FUNC_NORETURN static void ec_host_cmd_thread(void *hc_handle, void *arg2, void *
}
found_handler = NULL;
STRUCT_SECTION_FOREACH(ec_host_cmd_handler, handler)
{
STRUCT_SECTION_FOREACH(ec_host_cmd_handler, handler) {
if (handler->id == rx_header->cmd_id) {
found_handler = handler;
break;