logging: rpc: log history support

include/logging/log_rpc.h

@@ -32,10 +32,26 @@ enum log_rpc_level {
 };
 
 /**
- * Sets the logging stream verbosity level.
+ * Log history handler.
  *
- * Configures the remote device to only stream log messages whose level is less
- * than or equal to the specified level.
+ * The type of a callback function that is invoked for each received log message
+ * while fetching the log history from the remote device.
+ *
+ * @param level		The message level, see @c log_rpc_level.
+ * @param msg		A pointer to the message payload.
+ * @param msg_len	The message payload length.
+ */
+typedef void (*log_rpc_history_handler_t)(enum log_rpc_level level, const char *msg,
+					  size_t msg_len);
+
+/**
+ * Sets the log streaming verbosity level.
+ *
+ * The log streaming is the feature of nRF RPC logging that allows receiving log
+ * messages as they are generated by the application running on the remote device.
+ *
+ * This function issues an nRF RPC command that configures the remote device to
+ * stream log messages whose level is less than or equal to the specified level.
  *
  * @param level		Logging level, see @c log_rpc_level.
  *
@@ -44,6 +60,42 @@ enum log_rpc_level {
  */
 int log_rpc_set_stream_level(enum log_rpc_level level);
 
+/**
+ * Sets the log history verbosity level.
+ *
+ * The log history is the feature of nRF RPC logging that allows saving log
+ * messages generated by the application running on the remote device into
+ * a ring buffer, and then retrieving the log history when needed.
+ *
+ * The function issues an nRF RPC command that configures the remote device to
+ * save log messages whose level is less than or equal to the specified level.
+ *
+ * @param level		Logging level, see @c log_rpc_level.
+ *
+ * @retval 0		On success.
+ * @retval -errno	On failure.
+ */
+int log_rpc_set_history_level(enum log_rpc_level level);
+
+/**
+ * Fetches the log history.
+ *
+ * The function issues an nRF RPC command that starts the log history transfer
+ * from the remote device. The @c handler callback function is invoked for each
+ * received log message. Additionally, it is invoked with @c msg argument set to
+ * NULL after all log messages have been received.
+ *
+ * @note If the function is called while the previous log history transfer is
+ *       still is in progress, the process is restarted from the current oldest
+ *       log message saved in the log history on the remote device.
+ *
+ * @param handler	History handler, see @c log_rpc_history_handler_t.
+ *
+ * @retval 0		On success.
+ * @retval -errno	On failure.
+ */
+int log_rpc_fetch_history(log_rpc_history_handler_t handler);
+
 /**
  * @brief Retrieves the crash log retained on the remote device.
  *

samples/nrf_rpc/protocols_serialization/client/src/log_rpc_shell.c

@@ -33,6 +33,72 @@ static int cmd_log_rpc_stream_level(const struct shell *sh, size_t argc, char *a
 	return 0;
 }
 
+static int cmd_log_rpc_history_level(const struct shell *sh, size_t argc, char *argv[])
+{
+	int rc = 0;
+	enum log_rpc_level level;
+
+	level = (enum log_rpc_level)shell_strtol(argv[1], 10, &rc);
+
+	if (rc) {
+		shell_error(sh, "Invalid argument: %d", rc);
+		return -EINVAL;
+	}
+
+	rc = log_rpc_set_history_level(level);
+
+	if (rc) {
+		shell_error(sh, "Error: %d", rc);
+		return -ENOEXEC;
+	}
+
+	return 0;
+}
+
+static const struct shell *shell;
+
+static void history_handler(enum log_rpc_level level, const char *msg, size_t msg_len)
+{
+	enum shell_vt100_color color;
+
+	if (!msg) {
+		shell_print(shell, "Done");
+		return;
+	}
+
+	switch (level) {
+	case LOG_RPC_LEVEL_INF:
+		color = SHELL_INFO;
+		break;
+	case LOG_RPC_LEVEL_WRN:
+		color = SHELL_WARNING;
+		break;
+	case LOG_RPC_LEVEL_ERR:
+		color = SHELL_ERROR;
+		break;
+	default:
+		color = SHELL_NORMAL;
+		break;
+	}
+
+	shell_fprintf(shell, color, "%.*s\n", msg_len, msg);
+}
+
+static int cmd_log_rpc_history_fetch(const struct shell *sh, size_t argc, char *argv[])
+{
+	int rc = 0;
+
+	shell = sh;
+	rc = log_rpc_fetch_history(history_handler);
+
+	if (rc) {
+		shell_error(sh, "Error: %d", rc);
+		return -ENOEXEC;
+	}
+
+	return 0;
+}
+
 static int cmd_log_rpc_crash(const struct shell *sh, size_t argc, char *argv[])
 {
 	int rc;
@@ -60,8 +126,12 @@ static int cmd_log_rpc_crash(const struct shell *sh, size_t argc, char *argv[])
 }
 
 SHELL_STATIC_SUBCMD_SET_CREATE(log_rpc_cmds,
-			       SHELL_CMD_ARG(stream_level, NULL, "Set stream logging level",
+			       SHELL_CMD_ARG(stream_level, NULL, "Set log streaming level",
 					     cmd_log_rpc_stream_level, 2, 0),
+			       SHELL_CMD_ARG(history_level, NULL, "Set log history level",
+					     cmd_log_rpc_history_level, 2, 0),
+			       SHELL_CMD_ARG(history_fetch, NULL, "Fetch log history",
+					     cmd_log_rpc_history_fetch, 1, 0),
 			       SHELL_CMD_ARG(crash, NULL, "Retrieve remote device crash log",
 					     cmd_log_rpc_crash, 1, 0),
 			       SHELL_SUBCMD_SET_END);

samples/nrf_rpc/protocols_serialization/server/snippets/log_rpc/log_rpc.conf

@@ -7,6 +7,7 @@
 CONFIG_LOG=y
 CONFIG_LOG_BACKEND_RPC=y
 CONFIG_LOG_BACKEND_RPC_CRASH_LOG=y
+CONFIG_LOG_BACKEND_RPC_HISTORY=y
 
 # nRF RPC requires slightly bigger stack than default
 CONFIG_LOG_PROCESS_THREAD_STACK_SIZE=1024

subsys/logging/CMakeLists.txt

@@ -8,4 +8,5 @@ if (CONFIG_LOG_FORWARDER_RPC OR CONFIG_LOG_BACKEND_RPC)
     zephyr_library()
     zephyr_library_sources_ifdef(CONFIG_LOG_FORWARDER_RPC log_forwarder_rpc.c)
     zephyr_library_sources_ifdef(CONFIG_LOG_BACKEND_RPC log_backend_rpc.c)
+    zephyr_library_sources_ifdef(CONFIG_LOG_BACKEND_RPC_HISTORY_STORAGE_RAM log_backend_rpc_history_ram.c)
 endif()

subsys/logging/Kconfig

@@ -38,8 +38,42 @@ config LOG_BACKEND_RPC_OUTPUT_BUFFER_SIZE
 	  Defines the size of stack buffer that is used by the RPC logging backend
 	  while formatting a log message.
 
+config LOG_BACKEND_RPC_HISTORY
+	bool "Log history support"
+	help
+	  Enables the feature to continuously store logs in a large ring buffer,
+	  and adds nRF RPC commands for configuring and fetching the log history.
+
+if LOG_BACKEND_RPC_HISTORY
+
+choice LOG_BACKEND_RPC_HISTORY_STORAGE_CHOICE
+	prompt "Log history storage type"
+	default LOG_BACKEND_RPC_HISTORY_STORAGE_RAM
+
+config LOG_BACKEND_RPC_HISTORY_STORAGE_RAM
+	bool "RAM buffer"
+
+endchoice # LOG_BACKEND_RPC_HISTORY_STORAGE_CHOICE
+
+config LOG_BACKEND_RPC_HISTORY_UPLOAD_THREAD_STACK_SIZE
+	int "Log history upload thread stack size"
+	default 1024
+
+config LOG_BACKEND_RPC_HISTORY_UPLOAD_CHUNK_SIZE
+	int "Log history upload chunk size"
+	default 1024
+
+config LOG_BACKEND_RPC_HISTORY_SIZE
+	int "Log history size"
+	depends on LOG_BACKEND_RPC_HISTORY_STORAGE_RAM
+	default 16384
+	help
+	  Size of the ring buffer used to store the log history, in bytes.
+
+endif # LOG_BACKEND_RPC_HISTORY
+
 config LOG_BACKEND_RPC_CRASH_LOG
-	bool "nRF RPC crash log"
+	bool "Crash log support"
 	select RETENTION
 	select RETENTION_MUTEX_FORCE_DISABLE
 	select RETAINED_MEM

subsys/logging/log_backend_rpc.c

@@ -11,12 +11,14 @@
  */
 
 #include "log_rpc_group.h"
+#include "log_backend_rpc_history.h"
 
 #include <logging/log_rpc.h>
 #include <nrf_rpc/nrf_rpc_serialize.h>
 
 #include <nrf_rpc_cbor.h>
 
+#include <zephyr/kernel.h>
 #include <zephyr/logging/log.h>
 #include <zephyr/logging/log_backend.h>
 #include <zephyr/logging/log_backend_std.h>
@@ -45,6 +47,18 @@ static bool panic_mode;
 static uint32_t log_format = LOG_OUTPUT_TEXT;
 static enum log_rpc_level stream_level = LOG_RPC_LEVEL_NONE;
 
+#ifdef CONFIG_LOG_BACKEND_RPC_HISTORY
+static enum log_rpc_level history_level = LOG_RPC_LEVEL_NONE;
+static void history_transfer_task(struct k_work *work);
+static K_MUTEX_DEFINE(history_transfer_mtx);
+static uint32_t history_transfer_id;
+static union log_msg_generic *history_cur_msg;
+static K_WORK_DEFINE(history_transfer_work, history_transfer_task);
+static K_THREAD_STACK_DEFINE(history_transfer_workq_stack,
+			     CONFIG_LOG_BACKEND_RPC_HISTORY_UPLOAD_THREAD_STACK_SIZE);
+static struct k_work_q history_transfer_workq;
+#endif
+
 /*
  * Verify that Zephyr logging level can be used as the nRF RPC logging level without translation.
  */
@@ -341,6 +355,14 @@ static void process(const struct log_backend *const backend, union log_msg_gener
 		 */
 		stream_message(msg);
 	}
+
+#ifdef CONFIG_LOG_BACKEND_RPC_HISTORY
+	max_level = history_level;
+
+	if (max_level != LOG_RPC_LEVEL_NONE && level <= max_level) {
+		log_rpc_history_push(msg_generic);
+	}
+#endif
 }
 
 static void panic(struct log_backend const *const backend)
@@ -354,6 +376,14 @@ static void panic(struct log_backend const *const backend)
 static void init(struct log_backend const *const backend)
 {
 	ARG_UNUSED(backend);
+
+#ifdef CONFIG_LOG_BACKEND_RPC_HISTORY
+	log_rpc_history_init();
+	k_work_queue_init(&history_transfer_workq);
+	k_work_queue_start(&history_transfer_workq, history_transfer_workq_stack,
+			   K_THREAD_STACK_SIZEOF(history_transfer_workq_stack),
+			   K_LOWEST_APPLICATION_THREAD_PRIO, NULL);
+#endif
 }
 
 static void dropped(const struct log_backend *const backend, uint32_t cnt)
@@ -410,3 +440,114 @@ static void log_rpc_set_stream_level_handler(const struct nrf_rpc_group *group,
 
 NRF_RPC_CBOR_CMD_DECODER(log_rpc_group, log_rpc_set_stream_level_handler,
 			 LOG_RPC_CMD_SET_STREAM_LEVEL, log_rpc_set_stream_level_handler, NULL);
+
+#ifdef CONFIG_LOG_BACKEND_RPC_HISTORY
+
+static void log_rpc_set_history_level_handler(const struct nrf_rpc_group *group,
+					      struct nrf_rpc_cbor_ctx *ctx, void *handler_data)
+{
+	enum log_rpc_level level;
+
+	level = (enum log_rpc_level)nrf_rpc_decode_uint(ctx);
+
+	if (!nrf_rpc_decoding_done_and_check(group, ctx)) {
+		nrf_rpc_err(-EBADMSG, NRF_RPC_ERR_SRC_RECV, group, LOG_RPC_CMD_SET_HISTORY_LEVEL,
+			    NRF_RPC_PACKET_TYPE_CMD);
+		return;
+	}
+
+	history_level = level;
+
+	nrf_rpc_rsp_send_void(group);
+}
+
+NRF_RPC_CBOR_CMD_DECODER(log_rpc_group, log_rpc_set_history_level_handler,
+			 LOG_RPC_CMD_SET_HISTORY_LEVEL, log_rpc_set_history_level_handler, NULL);
+
+static void history_transfer_task(struct k_work *work)
+{
+	const uint32_t flags = common_output_flags | LOG_OUTPUT_FLAG_CRLF_NONE;
+
+	struct nrf_rpc_cbor_ctx ctx;
+	bool any_msg_consumed = false;
+	struct log_msg *msg;
+	size_t length;
+	size_t max_length;
+
+	NRF_RPC_CBOR_ALLOC(&log_rpc_group, ctx, CONFIG_LOG_BACKEND_RPC_HISTORY_UPLOAD_CHUNK_SIZE);
+
+	k_mutex_lock(&history_transfer_mtx, K_FOREVER);
+	nrf_rpc_encode_uint(&ctx, history_transfer_id);
+
+	while (true) {
+		if (!history_cur_msg) {
+			history_cur_msg = log_rpc_history_pop();
+		}
+
+		if (!history_cur_msg) {
+			break;
+		}
+
+		msg = &history_cur_msg->log;
+		length = 6 + format_message_to_buf(msg, flags, NULL, 0);
+		max_length = ctx.zs[0].payload_end - ctx.zs[0].payload_mut;
+
+		/* Check if there is enough buffer space to fit in the current message. */
+		if (length > max_length) {
+			break;
+		}
+
+		nrf_rpc_encode_uint(&ctx, log_msg_get_level(msg));
+
+		if (zcbor_bstr_start_encode(ctx.zs)) {
+			max_length = ctx.zs[0].payload_end - ctx.zs[0].payload_mut;
+			length = format_message_to_buf(msg, flags, ctx.zs[0].payload_mut,
+						       max_length);
+			ctx.zs[0].payload_mut += MIN(length, max_length);
+			zcbor_bstr_end_encode(ctx.zs, NULL);
+		}
+
+		log_rpc_history_free(history_cur_msg);
+		history_cur_msg = NULL;
+		any_msg_consumed = true;
+	}
+
+	/* Determine if the work should be resubmitted to continue the transfer. */
+	if (any_msg_consumed) {
+		k_work_submit_to_queue(&history_transfer_workq, work);
+	} else {
+		log_rpc_history_free(history_cur_msg);
+		history_cur_msg = NULL;
+	}
+
+	k_mutex_unlock(&history_transfer_mtx);
+
+	nrf_rpc_cbor_cmd_no_err(&log_rpc_group, LOG_RPC_CMD_PUT_HISTORY_CHUNK, &ctx,
+				nrf_rpc_rsp_decode_void, NULL);
+}
+
+static void log_rpc_fetch_history_handler(const struct nrf_rpc_group *group,
+					  struct nrf_rpc_cbor_ctx *ctx, void *handler_data)
+{
+	uint32_t transfer_id;
+
+	transfer_id = nrf_rpc_decode_uint(ctx);
+
+	if (!nrf_rpc_decoding_done_and_check(group, ctx)) {
+		nrf_rpc_err(-EBADMSG, NRF_RPC_ERR_SRC_RECV, group, LOG_RPC_CMD_FETCH_HISTORY,
+			    NRF_RPC_PACKET_TYPE_CMD);
+		return;
+	}
+
+	k_mutex_lock(&history_transfer_mtx, K_FOREVER);
+	history_transfer_id = transfer_id;
+	k_work_submit_to_queue(&history_transfer_workq, &history_transfer_work);
+	k_mutex_unlock(&history_transfer_mtx);
+
+	nrf_rpc_rsp_send_void(group);
+}
+
+NRF_RPC_CBOR_CMD_DECODER(log_rpc_group, log_rpc_fetch_history_handler, LOG_RPC_CMD_FETCH_HISTORY,
+			 log_rpc_fetch_history_handler, NULL);
+
+#endif