diff --git a/include/shell/shell.h b/include/shell/shell.h index 8ef37a7297b..8c00e2cf56a 100644 --- a/include/shell/shell.h +++ b/include/shell/shell.h @@ -11,7 +11,7 @@ #include #include #include -#include +#include #include #include #include @@ -266,6 +266,19 @@ struct shell_transport { void *ctx; }; +/** @brief Shell statistics structure. */ +struct shell_stats { + u32_t log_lost_cnt; /*!< Lost log counter.*/ +}; + +#if CONFIG_SHELL_STATS +#define SHELL_STATS_DEFINE(_name) static struct shell_stats _name##_stats +#define SHELL_STATS_PTR(_name) (&(_name##_stats)) +#else +#define SHELL_STATS_DEFINE(_name) +#define SHELL_STATS_PTR(_name) NULL +#endif /* CONFIG_SHELL_STATS */ + /* * @internal @brief Flags for internal shell usage. */ @@ -292,6 +305,7 @@ union shell_internal { enum shell_signal { SHELL_SIGNAL_RXRDY, SHELL_SIGNAL_TXDONE, + SHELL_SIGNAL_LOG_MSG, SHELL_SIGNAL_KILL, SHELL_SIGNALS }; @@ -344,6 +358,10 @@ struct shell { const struct shell_fprintf *fprintf_ctx; + struct shell_stats *stats; + + const struct shell_log_backend *log_backend; + LOG_INSTANCE_PTR_DECLARE(log); /*!< New line character, only allowed values: \\n and \\r.*/ @@ -368,11 +386,14 @@ struct shell { static const struct shell _name; \ static struct shell_ctx UTIL_CAT(_name, _ctx); \ static u8_t _name##_out_buffer[CONFIG_SHELL_PRINTF_BUFF_SIZE]; \ + SHELL_LOG_BACKEND_DEFINE(_name, _name##_out_buffer, \ + CONFIG_SHELL_PRINTF_BUFF_SIZE); \ SHELL_HISTORY_DEFINE(_name, 128, 8);/*todo*/ \ SHELL_FPRINTF_DEFINE(_name## _fprintf, &_name, _name##_out_buffer, \ CONFIG_SHELL_PRINTF_BUFF_SIZE, \ true, shell_print_stream); \ LOG_INSTANCE_REGISTER(shell, _name, CONFIG_SHELL_LOG_LEVEL); \ + SHELL_STATS_DEFINE(_name); \ static K_THREAD_STACK_DEFINE(_name##_stack, CONFIG_SHELL_STACK_SIZE);\ static struct k_thread _name##_thread; \ static const struct shell _name = { \ @@ -381,6 +402,8 @@ struct shell { .ctx = &UTIL_CAT(_name, _ctx), \ .history = SHELL_HISTORY_PTR(_name), \ .fprintf_ctx = &_name##_fprintf, \ + .stats = SHELL_STATS_PTR(_name), \ + .log_backend = SHELL_LOG_BACKEND_PTR(_name), \ LOG_INSTANCE_PTR_INIT(log, shell, _name) \ .newline_char = newline_ch, \ .thread = &_name##_thread, \ diff --git a/include/shell/shell_log_backend.h b/include/shell/shell_log_backend.h new file mode 100644 index 00000000000..2c60de53c8a --- /dev/null +++ b/include/shell/shell_log_backend.h @@ -0,0 +1,104 @@ +/* + * Copyright (c) 2018 Nordic Semiconductor ASA + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#ifndef SHELL_LOG_BACKEND_H__ +#define SHELL_LOG_BACKEND_H__ + +#include +#include +#include +#include +#ifdef __cplusplus +extern "C" { +#endif + +extern const struct log_backend_api log_backend_shell_api; + +/** @brief Shell log backend states. */ +enum shell_log_backend_state { + SHELL_LOG_BACKEND_UNINIT, + SHELL_LOG_BACKEND_ENABLED, + SHELL_LOG_BACKEND_DISABLED, + SHELL_LOG_BACKEND_PANIC, +}; + +/** @brief Shell log backend control block (RW data). */ +struct shell_log_backend_control_block { + atomic_t cnt; + enum shell_log_backend_state state; +}; + +/** @brief Shell log backend instance structure (RO data). */ +struct shell_log_backend { + const struct log_backend *backend; + struct k_fifo *fifo; + const struct log_output *log_output; + struct shell_log_backend_control_block *control_block; +}; + +/** @brief Prototype of function outputing processed data. */ +int shell_log_backend_output_func(u8_t *data, size_t length, void *ctx); + +/** @def SHELL_LOG_BACKEND_DEFINE + * @brief Macro for creating instance of shell log backend. + * + * @param _name Shell name. + * @param _buf Output buffer. + * @param _size Output buffer size. + */ +/** @def SHELL_LOG_BACKEND_PTR + * @brief Macro for retrieving pointer to the instance of shell log backend. + * + * @param _name Shell name. + */ +#if CONFIG_LOG +#define SHELL_LOG_BACKEND_DEFINE(_name, _buf, _size) \ + LOG_BACKEND_DEFINE(_name##_backend, log_backend_shell_api); \ + K_FIFO_DEFINE(_name##_fifo); \ + LOG_OUTPUT_DEFINE(_name##_log_output, shell_log_backend_output_func, \ + _buf, _size); \ + static struct shell_log_backend_control_block _name##_control_block; \ + static const struct shell_log_backend _name##_log_backend = { \ + .backend = &_name##_backend, \ + .fifo = &_name##_fifo, \ + .log_output = &_name##_log_output, \ + .control_block = &_name##_control_block \ + } + +#define SHELL_LOG_BACKEND_PTR(_name) (&_name##_log_backend) +#else /* CONFIG_LOG */ +#define SHELL_LOG_BACKEND_DEFINE(_name, _buf, _size) /* empty */ +#define SHELL_LOG_BACKEND_PTR(_name) NULL +#endif /* CONFIG_LOG */ + +/** @brief Enable shell log backend. + * + * @param backend Shell log backend instance. + * @param ctx Pointer to shell instance. + * @param init_log_level Initial log level set to all logging sources. + */ +void shell_log_backend_enable(const struct shell_log_backend *backend, + void *ctx, u32_t init_log_level); + +/** @brief Disable shell log backend. + * + * @param backend Shell log backend instance. + */ +void shell_log_backend_disable(const struct shell_log_backend *backend); + +/** @brief Trigger processing of one log entry. + * + * @param backend Shell log backend instance. + * + * @return True if message was processed, false if FIFO was empty + */ +bool shell_log_backend_process(const struct shell_log_backend *backend); + +#ifdef __cplusplus +} +#endif + +#endif /* SHELL_LOG_BACKEND_H__ */ diff --git a/subsys/shell/CMakeLists.txt b/subsys/shell/CMakeLists.txt index 99ad93e6487..85187a3f774 100644 --- a/subsys/shell/CMakeLists.txt +++ b/subsys/shell/CMakeLists.txt @@ -19,12 +19,17 @@ zephyr_sources_ifdef( shell_uart.c ) +zephyr_sources_ifdef( + CONFIG_SHELL_CMDS + shell_cmds.c +) + zephyr_sources_ifdef( CONFIG_SHELL_HISTORY shell_history.c ) zephyr_sources_ifdef( - CONFIG_SHELL_CMDS - shell_cmds.c + CONFIG_LOG + shell_log_backend.c ) diff --git a/subsys/shell/Kconfig b/subsys/shell/Kconfig index d153341d014..269e9844728 100644 --- a/subsys/shell/Kconfig +++ b/subsys/shell/Kconfig @@ -135,6 +135,17 @@ config SHELL_HISTORY_BUFFER endif #SHELL_HISTORY +config SHELL_MAX_LOG_MSG_BUFFERED + int "Maximal number of log messages in FIFO" + default 8 + help + When amount of buffered log messages exceeds this threshold oldest + messages are discarded. + +config SHELL_STATS + bool "Enable shell statistics" + default y + config SHELL_CMDS bool "Enable built-in commands" default y diff --git a/subsys/shell/shell.c b/subsys/shell/shell.c index 536ff28f4d8..df0b0c4a5a2 100644 --- a/subsys/shell/shell.c +++ b/subsys/shell/shell.c @@ -1033,6 +1033,44 @@ static void shell_transport_evt_handler(enum shell_transport_evt evt_type, k_poll_signal(signal, 0); } +static void shell_current_command_erase(const struct shell *shell) +{ + shell_multiline_data_calc(&shell->ctx->vt100_ctx.cons, + shell->ctx->cmd_buff_pos, + shell->ctx->cmd_buff_len); + shell_op_cursor_horiz_move(shell, -shell->ctx->vt100_ctx.cons.cur_x); + shell_op_cursor_vert_move(shell, shell->ctx->vt100_ctx.cons.cur_y - 1); + + clear_eos(shell); +} + +static void shell_current_command_print(const struct shell *shell) +{ + shell_fprintf(shell, SHELL_INFO, "%s", shell->name); + + if (flag_echo_is_set(shell)) { + shell_fprintf(shell, SHELL_NORMAL, "%s", shell->ctx->cmd_buff); + shell_op_cursor_position_synchronize(shell); + } +} + +static void shell_log_process(const struct shell *shell) +{ + bool processed; + int signaled; + int result; + + do { + shell_current_command_erase(shell); + processed = shell_log_backend_process(shell->log_backend); + shell_current_command_print(shell); + + k_poll_signal_check(&shell->ctx->signals[SHELL_SIGNAL_RXRDY], + &signaled, &result); + + } while (processed && !signaled); +} + static int shell_instance_init(const struct shell *shell, const void *p_config, bool use_colors) { @@ -1057,6 +1095,10 @@ static int shell_instance_init(const struct shell *shell, const void *p_config, shell->ctx->internal.flags.mode_delete = 1; } + if (IS_ENABLED(CONFIG_SHELL_STATS)) { + shell->stats->log_lost_cnt = 0; + } + shell->ctx->internal.flags.tx_rdy = 1; shell->ctx->internal.flags.echo = CONFIG_SHELL_ECHO_STATUS; shell->ctx->state = SHELL_STATE_INITIALIZED; @@ -1106,13 +1148,23 @@ void shell_thread(void *shell_handle, void *dummy1, void *dummy2) (void)shell_instance_uninit(shell); k_thread_abort(k_current_get()); - } else { + } + + k_poll_signal_check(&shell->ctx->signals[SHELL_SIGNAL_LOG_MSG], + &signaled, &result); + + if (!signaled) { /* Other signals handled together.*/ k_poll_signal_reset( &shell->ctx->signals[SHELL_SIGNAL_RXRDY]); k_poll_signal_reset( &shell->ctx->signals[SHELL_SIGNAL_TXDONE]); shell_process(shell); + } else if (IS_ENABLED(CONFIG_LOG)) { + k_poll_signal_reset( + &shell->ctx->signals[SHELL_SIGNAL_LOG_MSG]); + /* process log msg */ + shell_log_process(shell); } } } @@ -1128,6 +1180,13 @@ int shell_init(const struct shell *shell, const void *transport_config, return err; } + if (log_backend) { + if (IS_ENABLED(CONFIG_LOG)) { + shell_log_backend_enable(shell->log_backend, + (void *)shell, init_log_level); + } + } + (void)k_thread_create(shell->thread, shell->stack, CONFIG_SHELL_STACK_SIZE, shell_thread, (void *)shell, NULL, NULL, @@ -1146,6 +1205,11 @@ static int shell_instance_uninit(const struct shell *shell) return -EBUSY; } + if (IS_ENABLED(CONFIG_LOG)) { + /* todo purge log queue */ + shell_log_backend_disable(shell->log_backend); + } + err = shell->iface->api->uninit(shell->iface); if (err != 0) { return err; diff --git a/subsys/shell/shell_log_backend.c b/subsys/shell/shell_log_backend.c new file mode 100644 index 00000000000..9f2200e83df --- /dev/null +++ b/subsys/shell/shell_log_backend.c @@ -0,0 +1,167 @@ +/* + * Copyright (c) 2018 Nordic Semiconductor ASA + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include +#include +#include "shell_ops.h" +#include + +int shell_log_backend_output_func(u8_t *data, size_t length, void *ctx) +{ + shell_print_stream(ctx, data, length); + return length; +} + +void shell_log_backend_enable(const struct shell_log_backend *backend, + void *ctx, u32_t init_log_level) +{ + log_backend_enable(backend->backend, ctx, init_log_level); + log_output_ctx_set(backend->log_output, ctx); + backend->control_block->cnt = 0; + backend->control_block->state = SHELL_LOG_BACKEND_ENABLED; +} + +static struct log_msg *msg_from_fifo(const struct shell_log_backend *backend) +{ + struct log_msg *msg = k_fifo_get(backend->fifo, K_NO_WAIT); + + if (msg) { + atomic_dec(&backend->control_block->cnt); + } + + return msg; +} + +static void fifo_flush(const struct shell_log_backend *backend) +{ + struct log_msg *msg = msg_from_fifo(backend); + + /* Flush log messages. */ + while (msg) { + log_msg_put(msg); + msg = msg_from_fifo(backend); + } +} + +static void msg_to_fifo(const struct shell *shell, + struct log_msg *msg) +{ + atomic_val_t cnt; + + k_fifo_put(shell->log_backend->fifo, msg); + + cnt = atomic_inc(&shell->log_backend->control_block->cnt); + + /* If there is too much queued free the oldest one. */ + if (cnt >= CONFIG_SHELL_MAX_LOG_MSG_BUFFERED) { + log_msg_put(msg_from_fifo(shell->log_backend)); + if (IS_ENABLED(CONFIG_SHELL_STATS)) { + shell->stats->log_lost_cnt++; + } + } +} + +void shell_log_backend_disable(const struct shell_log_backend *backend) +{ + fifo_flush(backend); + log_backend_disable(backend->backend); + backend->control_block->state = SHELL_LOG_BACKEND_DISABLED; +} + +static void msg_process(const struct log_output *log_output, + struct log_msg *msg) +{ + u32_t flags = 0; + + if (IS_ENABLED(CONFIG_SHELL)) { + flags |= LOG_OUTPUT_FLAG_COLORS; + } + + if (IS_ENABLED(CONFIG_SHELL)) { + flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP; + } + + log_output_msg_process(log_output, msg, flags); + log_msg_put(msg); +} + +bool shell_log_backend_process(const struct shell_log_backend *backend) +{ + const struct shell *shell = + (const struct shell *)backend->backend->cb->ctx; + struct log_msg *msg = msg_from_fifo(backend); + + if (!msg) { + return false; + } + + msg_process(shell->log_backend->log_output, msg); + + return true; +} + +static void put(const struct log_backend *const backend, struct log_msg *msg) +{ + const struct shell *shell = (const struct shell *)backend->cb->ctx; + struct k_poll_signal *signal; + + log_msg_get(msg); + + switch (shell->log_backend->control_block->state) { + case SHELL_LOG_BACKEND_ENABLED: + msg_to_fifo(shell, msg); + + if (IS_ENABLED(CONFIG_MULTITHREADING)) { + signal = &shell->ctx->signals[SHELL_SIGNAL_LOG_MSG]; + k_poll_signal(signal, 0); + } + + break; + + case SHELL_LOG_BACKEND_PANIC: + msg_process(shell->log_backend->log_output, msg); + break; + + case SHELL_LOG_BACKEND_DISABLED: + /* fall through */ + /* no break */ + default: + /* Discard message. */ + log_msg_put(msg); + } +} + +static void panic(const struct log_backend *const backend) +{ + const struct shell *shell = (const struct shell *)backend->cb->ctx; + int err; + + err = shell->iface->api->enable(shell->iface, true); + + if (err == 0) { + shell->log_backend->control_block->state = + SHELL_LOG_BACKEND_PANIC; + + /* Move to the start of next line. */ + shell_multiline_data_calc(&shell->ctx->vt100_ctx.cons, + shell->ctx->cmd_buff_pos, + shell->ctx->cmd_buff_len); + shell_op_cursor_vert_move(shell, -1); + shell_op_cursor_horiz_move(shell, + -shell->ctx->vt100_ctx.cons.cur_x); + + while (shell_log_backend_process(shell->log_backend)) { + /* empty */ + } + } else { + shell_log_backend_disable(shell->log_backend); + } +} + +const struct log_backend_api log_backend_shell_api = { + .put = put, + .panic = panic +};