shell: Extend shell as a log backend
Initial logger backend support added to shell.
Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
diff --git a/include/shell/shell.h b/include/shell/shell.h
index 8ef37a7..8c00e2c 100644
--- a/include/shell/shell.h
+++ b/include/shell/shell.h
@@ -11,7 +11,7 @@
#include <shell/shell_types.h>
#include <shell/shell_history.h>
#include <shell/shell_fprintf.h>
-#include <logging/log_backend.h>
+#include <shell/shell_log_backend.h>
#include <logging/log_instance.h>
#include <logging/log.h>
#include <misc/util.h>
@@ -266,6 +266,19 @@
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 @@
enum shell_signal {
SHELL_SIGNAL_RXRDY,
SHELL_SIGNAL_TXDONE,
+ SHELL_SIGNAL_LOG_MSG,
SHELL_SIGNAL_KILL,
SHELL_SIGNALS
};
@@ -344,6 +358,10 @@
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 @@
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 @@
.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 0000000..2c60de5
--- /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 <zephyr.h>
+#include <logging/log_backend.h>
+#include <logging/log_output.h>
+#include <atomic.h>
+#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 99ad93e..85187a3 100644
--- a/subsys/shell/CMakeLists.txt
+++ b/subsys/shell/CMakeLists.txt
@@ -20,11 +20,16 @@
)
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 d153341..269e984 100644
--- a/subsys/shell/Kconfig
+++ b/subsys/shell/Kconfig
@@ -135,6 +135,17 @@
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 536ff28..df0b0c4 100644
--- a/subsys/shell/shell.c
+++ b/subsys/shell/shell.c
@@ -1033,6 +1033,44 @@
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 @@
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_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 @@
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 @@
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 0000000..9f2200e
--- /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 <shell/shell_log_backend.h>
+#include <shell/shell.h>
+#include "shell_ops.h"
+#include <logging/log_ctrl.h>
+
+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
+};
