jsonrpc: Write request and response object into a log file and stderr

Print JSON RPC request and response objects into a specified log file
and stderr via spdk_flog() and spdk_log(). To enable these logging, add
two public APIs, spdk_jsonrpc_set_log_level() and
spdk_jsonrpc_set_log_file().

Remove newlines of JSON objects to print it in a single line. We do this
by default because newline does not affect the functionality of JSON
RPC.

Another idea is to pass file name and file mode (append, write, ...).
However, SPDK is library. The application should manage log file. Hence,
we receive file pointer.

Signed-off-by: Shuhei Matsumoto <[email protected]>
Change-Id: Ia385181f3922077670767d72bd070391dad75b1d
Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/18829
Reviewed-by: Jim Harris <[email protected]>
Community-CI: Mellanox Build Bot
Tested-by: SPDK CI Jenkins <[email protected]>
Reviewed-by: Konrad Sztyber <[email protected]>

CHANGELOG.md

@@ -22,6 +22,11 @@ The `spdk_nvmf_request::data` field has been removed: instead, clients should se
 `->iov` and `->iovcnt` appropriately, as nvmf request APIs now expect any data
 buffers to be described there. spdk_nvmf_request_get_data() has been removed.
 
+### jsonrpc
+
+New APIs, `spdk_jsonrpc_set_log_level` and `spdk_jsonrpc_set_log_file`, were added to enable
+logging JSON RPC calls history.
+
 ## v23.05
 
 ### accel

include/spdk/jsonrpc.h

@@ -1,6 +1,6 @@
 /*   SPDX-License-Identifier: BSD-3-Clause
- *   Copyright (C) 2016 Intel Corporation.
- *   All rights reserved.
+ *   Copyright (C) 2016 Intel Corporation. All rights reserved.
+ *   Copyright (c) 2023 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
  */
 
 /**
@@ -14,6 +14,7 @@
 #include "spdk/stdinc.h"
 
 #include "spdk/json.h"
+#include "spdk/log.h"
 
 #ifdef __cplusplus
 extern "C" {
@@ -324,6 +325,25 @@ struct spdk_jsonrpc_client_response *spdk_jsonrpc_client_get_response(struct spd
  */
 void spdk_jsonrpc_client_free_response(struct spdk_jsonrpc_client_response *resp);
 
+/**
+ * Set the log level used by the JSON-RPC server to log RPC request and response objects.
+ *
+ * NOTE: This function should be called only before starting the JSON-RPC server.
+ * Users should set the level set by this function higher than the level set by
+ * spdk_log_set_print_level() or spdk_log_set_level().
+ *
+ * \param level Log level used to log RPC objects.
+ */
+void spdk_jsonrpc_set_log_level(enum spdk_log_level level);
+
+/**
+ * Set the log file used by the JSON-RPC server to log RPC request and response objects.
+ *
+ * NOTE: This function should be called only before starting the JSON-RPC server.
+ *
+ * \param file Log file pointer used to log RPC objects.
+ */
+void spdk_jsonrpc_set_log_file(FILE *file);
 
 #ifdef __cplusplus
 }

lib/jsonrpc/Makefile

@@ -7,7 +7,7 @@ SPDK_ROOT_DIR := $(abspath $(CURDIR)/../..)
 include $(SPDK_ROOT_DIR)/mk/spdk.common.mk
 
 SO_VER := 5
-SO_MINOR := 0
+SO_MINOR := 1
 
 LIBNAME = jsonrpc
 C_SRCS = jsonrpc_server.c jsonrpc_server_tcp.c

lib/jsonrpc/jsonrpc_server.c

@@ -1,19 +1,68 @@
 /*   SPDX-License-Identifier: BSD-3-Clause
- *   Copyright (C) 2016 Intel Corporation.
- *   All rights reserved.
+ *   Copyright (C) 2016 Intel Corporation. All rights reserved.
+ *   Copyright (c) 2023 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
  */
 
 #include "jsonrpc_internal.h"
 
 #include "spdk/util.h"
 
+static enum spdk_log_level g_rpc_log_level = SPDK_LOG_DISABLED;
+static FILE *g_rpc_log_file = NULL;
+
 struct jsonrpc_request {
 	const struct spdk_json_val *version;
 	const struct spdk_json_val *method;
 	const struct spdk_json_val *params;
 	const struct spdk_json_val *id;
 };
 
+void
+spdk_jsonrpc_set_log_level(enum spdk_log_level level)
+{
+	assert(level >= SPDK_LOG_DISABLED);
+	assert(level <= SPDK_LOG_DEBUG);
+	g_rpc_log_level = level;
+}
+
+void
+spdk_jsonrpc_set_log_file(FILE *file)
+{
+	g_rpc_log_file = file;
+}
+
+static void
+remove_newlines(char *text)
+{
+	int i = 0, j = 0;
+
+	while (text[i] != '\0') {
+		if (text[i] != '\n') {
+			text[j++] = text[i];
+		}
+		i++;
+	}
+	text[j] = '\0';
+}
+
+static void
+jsonrpc_log(char *buf, const char *prefix)
+{
+	/* Remove newlines to print in a single line.
+	 * Newlines does not affect the functionality of JSON RPC objects.
+	 * Hence for simplicity, remove newlines by default.
+	 */
+	remove_newlines(buf);
+
+	if (g_rpc_log_level != SPDK_LOG_DISABLED) {
+		spdk_log(g_rpc_log_level, NULL, 0, NULL, "%s%s\n", prefix, buf);
+	}
+
+	if (g_rpc_log_file != NULL) {
+		spdk_flog(g_rpc_log_file, NULL, 0, NULL, "%s%s\n", prefix, buf);
+	}
+}
+
 static int
 capture_val(const struct spdk_json_val *val, void *out)
 {
@@ -152,6 +201,8 @@ jsonrpc_parse_request(struct spdk_jsonrpc_server_conn *conn, const void *json, s
 	memcpy(request->recv_buffer, json, len);
 	request->recv_buffer[len] = '\0';
 
+	jsonrpc_log(request->recv_buffer, "request: ");
+
 	if (rc > 0 && rc <= SPDK_JSONRPC_MAX_VALUES) {
 		request->values_cnt = rc;
 		request->values = malloc(request->values_cnt * sizeof(request->values[0]));
@@ -281,6 +332,8 @@ jsonrpc_free_request(struct spdk_jsonrpc_request *request)
 void
 jsonrpc_complete_request(struct spdk_jsonrpc_request *request)
 {
+	jsonrpc_log(request->send_buf, "response: ");
+
 	jsonrpc_free_request(request);
 }
 

lib/jsonrpc/spdk_jsonrpc.map

@@ -23,6 +23,8 @@
 	spdk_jsonrpc_client_poll;
 	spdk_jsonrpc_client_get_response;
 	spdk_jsonrpc_client_free_response;
+	spdk_jsonrpc_set_log_level;
+	spdk_jsonrpc_set_log_file;
 
 	local: *;
 };