From 107738848df07a66ae4d7c5af8f73a98ca555224 Mon Sep 17 00:00:00 2001 From: Dawid Niedzwiecki Date: Mon, 28 Jun 2021 15:24:17 +0200 Subject: zephyr: switch to using shell_*, not printk Reimplement the printf functions for Zephyr to use shell_* functions instead of printk. The main differences are: -UART output is buffered by the shell layer. The size of the buffer should be adjusted per board (SHELL_BACKEND_SERIAL_TX_RING_BUFFER_SIZE) -The shell uses non-blocking UART FIFO operations while printk waits actively for every sent byte. -The shell prints can not be split by the other shell prints so it should increase the quality of the output. However the shell_* functions can not be used in interrupts, so use printk instead which can divide the shell output. The output may be messy for boards that have a lot of prints in interrupts e.g. volteer. EC uses unusual print format e.g. "%pT" to print a timestamp, so use the CrosEC's vfnprintf function and then pass the generated string to the shell_* print. Use the sprintf function for that purpose. Long term, the EC codebase should switch to a usual print format, so shell_* can be used directly and not 2 versions of vfnprintf. This change should also help to pass tests that wait for a certain pattern on output e.g. ECBootTime. BUG=b:191724484, b:178033156 BRANCH=none TEST=Verify the console output works Signed-off-by: Dawid Niedzwiecki Change-Id: Ifaed2093ab8c43038c7d3e0ded1449a93f7f7da5 Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/platform/ec/+/2988194 Reviewed-by: Keith Short Commit-Queue: Keith Short --- common/console_output.c | 2 + common/printf.c | 13 ++---- include/printf.h | 19 ++++++-- zephyr/shim/src/console.c | 112 +++++++++++++++++++++++++++++++++++++++++----- 4 files changed, 123 insertions(+), 23 deletions(-) diff --git a/common/console_output.c b/common/console_output.c index aa7a558bf7..33b1466181 100644 --- a/common/console_output.c +++ b/common/console_output.c @@ -72,6 +72,7 @@ bool console_channel_is_disabled(enum console_channel channel) } #endif /* CONFIG_CONSOLE_CHANNEL */ +#ifndef CONFIG_ZEPHYR /*****************************************************************************/ /* Channel-based console output */ @@ -135,6 +136,7 @@ int cprints(enum console_channel channel, const char *format, ...) r = cputs(channel, "]\n"); return r ? r : rv; } +#endif /* CONFIG_ZEPHYR */ void cflush(void) { diff --git a/common/printf.c b/common/printf.c index 14226800b6..be06d34dd8 100644 --- a/common/printf.c +++ b/common/printf.c @@ -463,12 +463,6 @@ int vfnprintf(int (*addchar)(void *context, int c), void *context, return EC_SUCCESS; } -/* - * These symbols are already defined by the Zephyr OS kernel, and we - * don't want to use the EC implementation. - */ -#ifndef CONFIG_ZEPHYR - /* Context for snprintf() */ struct snprintf_context { char *str; @@ -494,19 +488,19 @@ static int snprintf_addchar(void *context, int c) return 0; } -int snprintf(char *str, size_t size, const char *format, ...) +int crec_snprintf(char *str, size_t size, const char *format, ...) { va_list args; int rv; va_start(args, format); - rv = vsnprintf(str, size, format, args); + rv = crec_vsnprintf(str, size, format, args); va_end(args); return rv; } -int vsnprintf(char *str, size_t size, const char *format, va_list args) +int crec_vsnprintf(char *str, size_t size, const char *format, va_list args) { struct snprintf_context ctx; int rv; @@ -525,4 +519,3 @@ int vsnprintf(char *str, size_t size, const char *format, va_list args) return (rv == EC_SUCCESS) ? (ctx.str - str) : -rv; } -#endif /* !CONFIG_ZEPHYR */ diff --git a/include/printf.h b/include/printf.h index 5c6373cf1e..37c0cc3949 100644 --- a/include/printf.h +++ b/include/printf.h @@ -12,6 +12,13 @@ #include /* For size_t */ #include "common.h" +/* The declaration of snprintf is changed to crec_snprintf for Zephyr, + * so include stdio.h from Zephyr. + */ +#ifdef CONFIG_ZEPHYR +#include +#endif + /* * Printf formatting: % [flags] [width] [.precision] [length] [type] * @@ -77,6 +84,11 @@ __stdlib_compat int vfnprintf(int (*addchar)(void *context, int c), void *context, const char *format, va_list args); +#ifndef CONFIG_ZEPHYR +#define snprintf crec_snprintf +#define vsnprintf crec_vsnprintf +#endif + /** * Print formatted outut to a string. * @@ -88,7 +100,8 @@ __stdlib_compat int vfnprintf(int (*addchar)(void *context, int c), * @return EC_SUCCESS, or EC_ERROR_OVERFLOW if the output was truncated. */ __attribute__((__format__(__printf__, 3, 4))) -__stdlib_compat int snprintf(char *str, size_t size, const char *format, ...); +__stdlib_compat int crec_snprintf(char *str, size_t size, const char *format, + ...); /** * Print formatted output to a string. @@ -102,8 +115,8 @@ __stdlib_compat int snprintf(char *str, size_t size, const char *format, ...); * @return The string length written to str, or a negative value on error. * The negative values can be -EC_ERROR_INVAL or -EC_ERROR_OVERFLOW. */ -__stdlib_compat int vsnprintf(char *str, size_t size, const char *format, - va_list args); +__stdlib_compat int crec_vsnprintf(char *str, size_t size, const char *format, + va_list args); #endif /* !HIDE_EC_STDLIB */ diff --git a/zephyr/shim/src/console.c b/zephyr/shim/src/console.c index 28f0067249..241c6f104b 100644 --- a/zephyr/shim/src/console.c +++ b/zephyr/shim/src/console.c @@ -12,11 +12,16 @@ #include #include #include +#include #include "console.h" #include "printf.h" #include "uart.h" +#include "usb_console.h" +LOG_MODULE_REGISTER(shim_console, LOG_LEVEL_ERR); + +static const struct shell *shell_zephyr; static struct k_poll_signal shell_uninit_signal; static struct k_poll_signal shell_init_signal; RING_BUF_DECLARE(rx_buffer, CONFIG_UART_RX_BUF_SIZE); @@ -189,16 +194,11 @@ static int init_ec_console(const struct device *unused) } SYS_INIT(init_ec_console, PRE_KERNEL_1, 50); #endif /* CONFIG_CONSOLE_CHANNEL && DT_NODE_EXISTS(DT_PATH(ec_console)) */ -/* - * Minimal implementation of a few uart_* functions we need. - * TODO(b/178033156): probably need to swap this for something more - * robust in order to handle UART buffering. - */ - -int uart_init_done(void) +static int init_ec_shell(const struct device *unused) { - return true; -} + shell_zephyr = shell_backend_uart_get_ptr(); + return 0; +} SYS_INIT(init_ec_shell, PRE_KERNEL_1, 50); void uart_tx_start(void) { @@ -225,6 +225,7 @@ void uart_write_char(char c) void uart_flush_output(void) { + shell_process(shell_zephyr); } void uart_tx_flush(void) @@ -244,6 +245,97 @@ int uart_getc(void) void uart_clear_input(void) { /* Clear any remaining shell processing. */ - shell_process(shell_backend_uart_get_ptr()); + shell_process(shell_zephyr); ring_buf_reset(&rx_buffer); } + +static void handle_sprintf_rv(int rv, size_t *len) +{ + if (rv < 0) { + LOG_ERR("Print buffer is too small"); + *len = CONFIG_SHELL_PRINTF_BUFF_SIZE; + } else { + *len += rv; + } +} + +static void zephyr_print(const char *buff, size_t size) +{ + /* shell_* functions can not be used in ISRs so use printk instead. + * Also, console_buf_notify_chars uses a mutex, which may not be + * locked in ISRs. + */ + if (k_is_in_isr() || shell_zephyr->ctx->state != SHELL_STATE_ACTIVE) + printk("%s", buff); + else { + shell_fprintf(shell_zephyr, SHELL_NORMAL, "%s", buff); + if (IS_ENABLED(CONFIG_PLATFORM_EC_HOSTCMD_CONSOLE)) + console_buf_notify_chars(buff, size); + } +} + +#if defined(CONFIG_USB_CONSOLE) || defined(CONFIG_USB_CONSOLE_STREAM) +BUILD_ASSERT(0, "USB console is not supported with Zephyr"); +#endif /* defined(CONFIG_USB_CONSOLE) || defined(CONFIG_USB_CONSOLE_STREAM) */ + +int cputs(enum console_channel channel, const char *outstr) +{ + /* Filter out inactive channels */ + if (console_channel_is_disabled(channel)) + return EC_SUCCESS; + + zephyr_print(outstr, strlen(outstr)); + + return 0; +} + +int cprintf(enum console_channel channel, const char *format, ...) +{ + int rv; + va_list args; + size_t len = 0; + char buff[CONFIG_SHELL_PRINTF_BUFF_SIZE]; + + /* Filter out inactive channels */ + if (console_channel_is_disabled(channel)) + return EC_SUCCESS; + + va_start(args, format); + rv = crec_vsnprintf(buff, CONFIG_SHELL_PRINTF_BUFF_SIZE, format, args); + va_end(args); + handle_sprintf_rv(rv, &len); + + zephyr_print(buff, len); + + return rv > 0 ? EC_SUCCESS : rv; +} + +int cprints(enum console_channel channel, const char *format, ...) +{ + int rv; + va_list args; + char buff[CONFIG_SHELL_PRINTF_BUFF_SIZE]; + size_t len = 0; + + /* Filter out inactive channels */ + if (console_channel_is_disabled(channel)) + return EC_SUCCESS; + + rv = crec_snprintf(buff, CONFIG_SHELL_PRINTF_BUFF_SIZE, "[%pT ", + PRINTF_TIMESTAMP_NOW); + handle_sprintf_rv(rv, &len); + + va_start(args, format); + rv = crec_vsnprintf(buff + len, CONFIG_SHELL_PRINTF_BUFF_SIZE - len, + format, args); + va_end(args); + handle_sprintf_rv(rv, &len); + + rv = crec_snprintf(buff + len, CONFIG_SHELL_PRINTF_BUFF_SIZE - len, + "]\n"); + handle_sprintf_rv(rv, &len); + + zephyr_print(buff, len); + + return rv > 0 ? EC_SUCCESS : rv; +} -- cgit v1.2.1