logging: rpc: add buffer usage threshold signaling

This commit introduces new threshold value specyfing when a RPC event
should be sent to the client based of current buffer's usage.

Signed-off-by: Konrad Derda <[email protected]>

include/logging/log_rpc.h

@@ -117,6 +117,32 @@ int log_rpc_fetch_history(log_rpc_history_handler_t handler);
  */
 int log_rpc_get_crash_log(size_t offset, char *buffer, size_t buffer_length);
 
+/**
+ * @brief Gets current buffer usage threshold.
+ *
+ * The function fetches the current buffer usage signal threshold (percent).
+ *
+ * @returns The current threshold.
+ */
+uint8_t log_rpc_get_buffer_usage_signal_threshold(void);
+
+/**
+ * @brief Sets current buffer usage threshold.
+ *
+ * The function sets a threshold (percentage of log buffer used) that is used as
+ * an indicator for the RPC server when it should inform the client about
+ * pending log history. When the given threshold is reached the log history is
+ * fetched with @c handler callback function invoked for each received log
+ * message. Additionally, it is invoked with @c msg argument set to
+ * NULL after all log messages have been received.
+ *
+ * @param handler   History handler, see @c log_rpc_history_handler_t.
+ * @param threshold Percentage (0 - 100) of buffer usage when handler should be called.
+ *                  0 disables signaling.
+ */
+void log_rpc_set_buffer_usage_signal_threshold(log_rpc_history_handler_t handler,
+					       uint8_t threshold);
+
 #ifdef __cplusplus
 }
 #endif

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

@@ -125,6 +125,36 @@ static int cmd_log_rpc_crash(const struct shell *sh, size_t argc, char *argv[])
 	return 0;
 }
 
+static int cmd_log_rpc_history_threshold(const struct shell *sh, size_t argc, char *argv[])
+{
+	uint32_t threshold;
+	int err = 0;
+
+	if (argc > 1) {
+		threshold = shell_strtoul(argv[1], 0, &err);
+
+		if (err) {
+			shell_error(sh, "Failed to parse threshold: %s", argv[1]);
+			return -ENOEXEC;
+		}
+
+		if (threshold > 100) {
+			shell_error(sh, "Value %u exceeds max value (100)");
+			return -ENOEXEC;
+		}
+
+		log_rpc_set_buffer_usage_signal_threshold(history_handler, (uint8_t)threshold);
+
+		return 0;
+	}
+
+	threshold = log_rpc_get_buffer_usage_signal_threshold();
+
+	shell_print(sh, "Current threshold: %u", threshold);
+
+	return 0;
+}
+
 SHELL_STATIC_SUBCMD_SET_CREATE(log_rpc_cmds,
 			       SHELL_CMD_ARG(stream_level, NULL, "Set log streaming level",
 					     cmd_log_rpc_stream_level, 2, 0),
@@ -134,6 +164,9 @@ SHELL_STATIC_SUBCMD_SET_CREATE(log_rpc_cmds,
 					     cmd_log_rpc_history_fetch, 1, 0),
 			       SHELL_CMD_ARG(crash, NULL, "Retrieve remote device crash log",
 					     cmd_log_rpc_crash, 1, 0),
+			       SHELL_CMD_ARG(history_threshold, NULL,
+					     "Get or set signaling threshold",
+					     cmd_log_rpc_history_threshold, 1, 0)
 			       SHELL_SUBCMD_SET_END);
 
 SHELL_CMD_ARG_REGISTER(log_rpc, &log_rpc_cmds, "RPC logging commands", NULL, 1, 0);

subsys/logging/log_backend_rpc.c

@@ -50,6 +50,7 @@ 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 void log_buffer_threshold_callback(void);
 static K_MUTEX_DEFINE(history_transfer_mtx);
 static uint32_t history_transfer_id;
 static union log_msg_generic *history_cur_msg;
@@ -378,7 +379,7 @@ static void init(struct log_backend const *const backend)
 	ARG_UNUSED(backend);
 
 #ifdef CONFIG_LOG_BACKEND_RPC_HISTORY
-	log_rpc_history_init();
+	log_rpc_history_init(log_buffer_threshold_callback);
 	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),
@@ -550,4 +551,44 @@ static void log_rpc_fetch_history_handler(const struct nrf_rpc_group *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);
 
+static void log_rpc_get_buffer_usage_threshold(const struct nrf_rpc_group *group,
+					       struct nrf_rpc_cbor_ctx *ctx, void *handler_data)
+{
+	nrf_rpc_decoding_done(group, ctx);
+	nrf_rpc_rsp_send_uint(group, log_rpc_history_threshold_get());
+}
+
+NRF_RPC_CBOR_CMD_DECODER(log_rpc_group, log_rpc_get_buffer_usage_threshold,
+			 LOG_RPC_CMD_GET_BUFFER_USAGE_THRESHOLD, log_rpc_get_buffer_usage_threshold,
+			 NULL);
+
+static void log_rpc_set_buffer_usage_threshold(const struct nrf_rpc_group *group,
+					       struct nrf_rpc_cbor_ctx *ctx, void *handler_data)
+{
+	uint8_t threshold = 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_BUFFER_USAGE_THRESHOLD, NRF_RPC_PACKET_TYPE_CMD);
+		return;
+	}
+
+	log_rpc_history_threshold_set(threshold);
+
+	nrf_rpc_rsp_send_void(group);
+}
+
+NRF_RPC_CBOR_CMD_DECODER(log_rpc_group, log_rpc_set_buffer_usage_threshold,
+			 LOG_RPC_CMD_SET_BUFFER_USAGE_THRESHOLD, log_rpc_set_buffer_usage_threshold,
+			 NULL);
+
+void log_buffer_threshold_callback(void)
+{
+	struct nrf_rpc_cbor_ctx ctx;
+
+	NRF_RPC_CBOR_ALLOC(&log_rpc_group, ctx, 0);
+
+	nrf_rpc_cbor_evt_no_err(&log_rpc_group, LOG_RPC_EVT_HISTORY_THRESHOLD_REACHED, &ctx);
+}
+
 #endif

subsys/logging/log_backend_rpc_history.h

@@ -9,11 +9,17 @@
 
 #include <zephyr/logging/log_msg.h>
 
-void log_rpc_history_init(void);
+/* Callback for reaching buffer usage threshold */
+typedef void (*log_rpc_history_buffer_thresh_callback_t)(void);
+
+void log_rpc_history_init(log_rpc_history_buffer_thresh_callback_t cb);
 
 void log_rpc_history_push(const union log_msg_generic *msg);
 
 union log_msg_generic *log_rpc_history_pop(void);
 void log_rpc_history_free(const union log_msg_generic *msg);
 
+uint8_t log_rpc_history_threshold_get(void);
+void log_rpc_history_threshold_set(uint8_t threshold);
+
 #endif /* LOG_RPC_HISTORY_H_ */

subsys/logging/log_backend_rpc_history_ram.c

@@ -13,8 +13,10 @@
 
 static uint32_t __aligned(Z_LOG_MSG_ALIGNMENT) log_history_raw[HISTORY_WLEN];
 static struct mpsc_pbuf_buffer log_history_pbuf;
+static uint8_t log_buffer_signal_threshold;
+static log_rpc_history_buffer_thresh_callback_t log_buffer_signal_cb;
 
-void log_rpc_history_init(void)
+void log_rpc_history_init(log_rpc_history_buffer_thresh_callback_t cb)
 {
 	const struct mpsc_pbuf_buffer_config log_history_config = {
 		.buf = log_history_raw,
@@ -23,6 +25,10 @@ void log_rpc_history_init(void)
 		.flags = MPSC_PBUF_MODE_OVERWRITE,
 	};
 
+	__ASSERT(cb);
+
+	log_buffer_signal_cb = cb;
+
 	mpsc_pbuf_init(&log_history_pbuf, &log_history_config);
 }
 
@@ -31,6 +37,8 @@ void log_rpc_history_push(const union log_msg_generic *msg)
 	uint32_t wlen;
 	union log_msg_generic *copy;
 	int len;
+	size_t total_size;
+	size_t current_size;
 
 	wlen = log_msg_generic_get_wlen(&msg->buf);
 	copy = (union log_msg_generic *)mpsc_pbuf_alloc(&log_history_pbuf, wlen, K_NO_WAIT);
@@ -45,6 +53,14 @@ void log_rpc_history_push(const union log_msg_generic *msg)
 	__ASSERT_NO_MSG(len == msg->log.hdr.desc.package_len);
 
 	mpsc_pbuf_commit(&log_history_pbuf, &copy->buf);
+
+	if (log_buffer_usage_threshold > 0) {
+		mpsc_pbuf_get_utilization(&log_history_pbuf, &total_size, &current_size);
+
+		if (((current_size * 100) / total_size) >= log_buffer_usage_threshold) {
+			log_buffer_signal_cb();
+		}
+	}
 }
 
 union log_msg_generic *log_rpc_history_pop(void)
@@ -60,3 +76,13 @@ void log_rpc_history_free(const union log_msg_generic *msg)
 
 	mpsc_pbuf_free(&log_history_pbuf, &msg->buf);
 }
+
+uint8_t log_rpc_history_threshold_get(void)
+{
+	return log_buffer_signal_threshold;
+}
+
+void log_rpc_history_threshold_set(uint8_t threshold)
+{
+	log_buffer_signal_threshold = threshold;
+}

subsys/logging/log_forwarder_rpc.c

@@ -26,6 +26,7 @@ LOG_MODULE_REGISTER(remote);
 static K_MUTEX_DEFINE(history_transfer_mtx);
 static uint32_t history_transfer_id;
 static log_rpc_history_handler_t history_handler;
+static log_rpc_history_handler_t history_signal_handler;
 
 static void log_rpc_msg_handler(const struct nrf_rpc_group *group, struct nrf_rpc_cbor_ctx *ctx,
 				void *handler_data)
@@ -191,3 +192,47 @@ int log_rpc_get_crash_log(size_t offset, char *buffer, size_t buffer_length)
 
 	return log_chunk_size;
 }
+
+static void log_rpc_history_threshold_handler(const struct nrf_rpc_group *group,
+					      struct nrf_rpc_cbor_ctx *ctx, void *handler_data)
+{
+	nrf_rpc_decoding_done(&log_rpc_group, ctx);
+
+	if (history_signal_handler) {
+		log_rpc_fetch_history(history_signal_handler);
+	}
+}
+
+NRF_RPC_CBOR_EVT_DECODER(log_rpc_group, log_rpc_history_threshold_handler,
+			 LOG_RPC_EVT_HISTORY_THRESHOLD_REACHED, log_rpc_history_threshold_handler,
+			 NULL);
+
+uint8_t log_rpc_get_buffer_usage_signal_threshold(void)
+{
+	struct nrf_rpc_cbor_ctx ctx;
+	uint8_t threshold;
+
+	NRF_RPC_CBOR_ALLOC(&log_rpc_group, ctx, 0);
+
+	nrf_rpc_cbor_cmd_rsp_no_err(&log_rpc_group, LOG_RPC_CMD_GET_BUFFER_USAGE_THRESHOLD, &ctx);
+	threshold = nrf_rpc_decode_uint(ctx);
+
+	if (!nrf_rpc_decoding_done_and_check(&log_rpc_group, &ctx)) {
+		nrf_rpc_err(-EBADMSG, NRF_RPC_ERR_SRC_RECV, &log_rpc_group,
+			    LOG_RPC_CMD_GET_BUFFER_USAGE_THRESHOLD, NRF_RPC_PACKET_TYPE_RSP);
+	}
+
+	return threshold;
+}
+
+void log_rpc_set_buffer_usage_signal_threshold(log_rpc_history_handler_t handler, uint8_t threshold)
+{
+	struct nrf_rpc_cbor_ctx ctx;
+
+	history_signal_handler =  handler;
+
+	NRF_RPC_CBOR_ALLOC(&log_rpc_group, ctx, 2);
+	nrf_rpc_encode_uint(&ctx, threshold);
+	nrf_rpc_cbor_cmd_no_err(&log_rpc_group, LOG_RPC_CMD_SET_BUFFER_USAGE_THRESHOLD, &ctx,
+				nrf_rpc_rsp_decode_void, NULL);
+}

subsys/logging/log_rpc_group.h

@@ -29,6 +29,7 @@ NRF_RPC_GROUP_DEFINE(log_rpc_group, "log", &log_rpc_tr, NULL, NULL, NULL);
 
 enum log_rpc_evt_forwarder {
 	LOG_RPC_EVT_MSG = 0,
+	LOG_RPC_EVT_HISTORY_THRESHOLD_REACHED = 1,
 };
 
 enum log_rpc_cmd_forwarder {
@@ -40,6 +41,8 @@ enum log_rpc_cmd_backend {
 	LOG_RPC_CMD_SET_HISTORY_LEVEL = 1,
 	LOG_RPC_CMD_FETCH_HISTORY = 2,
 	LOG_RPC_CMD_GET_CRASH_LOG = 3,
+	LOG_RPC_CMD_GET_BUFFER_USAGE_THRESHOLD = 4,
+	LOG_RPC_CMD_SET_BUFFER_USAGE_THRESHOLD = 5,
 };
 
 #ifdef __cplusplus