[dpdk-dev] Proposal: enable redirection of DPDK logs from the user app

[Montorsi, Francesco]

Hi Olivier,

> It seems the mailing list stripped your patch sent as attachment.
> Can you please resend it again in the body of the mail?
You're right sorry. It's attached at the end of this mail.

> I think we can already redirect logs to a file by using fopencookie() +
> rte_openlog_stream(). Did you already check these functions?

Yes, but to be honest, that seems a troublesome solution for something as easy as logging a string; e.g. by using fopencookie() approach, you don't have the concept of "log message", you just provide a function that must write a block of bytes somewhere.  Typically instead, you need to know where a log message starts and ends, to e.g., add prefixes/postfixes to it.

Indeed, most of the C/C++ (open source) libraries have some simple hook that allows the user to have more control on logging... I think DPDK should be no exception... :)

Thanks,
Francesco



>From 52d4fdccee4de3787e85589ff8f666028ad9ea7b Mon Sep 17 00:00:00 2001
From: Francesco Montorsi <fmontorsi at empirix.com>
Date: Tue, 4 Oct 2016 12:08:34 +0200
Subject: [PATCH] Enable custom log sink implementations

---
 lib/librte_eal/common/eal_common_log.c          | 23 ++++++++++++++++++++---
 lib/librte_eal/common/include/rte_log.h         |  8 ++++++--
 lib/librte_eal/linuxapp/eal/eal_debug.c         | 16 ++++++++++++++--
 lib/librte_eal/linuxapp/eal/rte_eal_version.map |  2 +-
 4 files changed, 41 insertions(+), 8 deletions(-)

diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
index 967991a..5e86309 100644
--- a/lib/librte_eal/common/eal_common_log.c
+++ b/lib/librte_eal/common/eal_common_log.c
@@ -41,15 +41,25 @@
 
 #include "eal_private.h"
 
+
+/* forward declaration */
+int
+rte_vlog_to_FILE(uint32_t level, uint32_t logtype, const char *formattedstr);
+
 /* global log structure */
 struct rte_logs rte_logs = {
 	.type = ~0,
 	.level = RTE_LOG_DEBUG,
 	.file = NULL,
+	.log_callback = rte_vlog_to_FILE
 };
 
 static FILE *default_log_stream;
 
+#define LOG_BUFFER_SIZE			4095
+static char log_buffer[LOG_BUFFER_SIZE+1];
+
+
 /**
  * This global structure stores some informations about the message
  * that is currently beeing processed by one lcore
@@ -123,7 +133,7 @@ int rte_log_cur_msg_logtype(void)
  * defined by the previous call to rte_openlog_stream().
  */
 int
-rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
+rte_vlog_to_FILE(uint32_t level, uint32_t logtype, const char *formattedstr)
 {
 	int ret;
 	FILE *f = rte_logs.file;
@@ -135,11 +145,16 @@ rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
 	RTE_PER_LCORE(log_cur_msg).loglevel = level;
 	RTE_PER_LCORE(log_cur_msg).logtype = logtype;
 
-	ret = vfprintf(f, format, ap);
+	ret = fprintf(f, "%s", formattedstr);
 	fflush(f);
 	return ret;
 }
 
+void rte_set_custom_vlog(rte_vlog_func_t callback)
+{
+	rte_logs.log_callback = callback;
+}
+
 /*
  * Generates a log message The message will be sent in the stream
  * defined by the previous call to rte_openlog_stream().
@@ -152,8 +167,10 @@ rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
 	int ret;
 
 	va_start(ap, format);
-	ret = rte_vlog(level, logtype, format, ap);
+	vsnprintf(log_buffer, LOG_BUFFER_SIZE, format, ap);
 	va_end(ap);
+
+	ret = rte_logs.log_callback(level, logtype, log_buffer);
 	return ret;
 }
 
diff --git a/lib/librte_eal/common/include/rte_log.h b/lib/librte_eal/common/include/rte_log.h
index 919563c..3dcb135 100644
--- a/lib/librte_eal/common/include/rte_log.h
+++ b/lib/librte_eal/common/include/rte_log.h
@@ -50,11 +50,15 @@ extern "C" {
 #include <stdio.h>
 #include <stdarg.h>
 
+/** The backend used for logging. Can be user-defined. */
+typedef int (*rte_vlog_func_t)(uint32_t level, uint32_t logtype, const char *formattedstr);
+
 /** The rte_log structure. */
 struct rte_logs {
 	uint32_t type;  /**< Bitfield with enabled logs. */
 	uint32_t level; /**< Log level. */
 	FILE *file;     /**< Pointer to current FILE* for logs. */
+	rte_vlog_func_t log_callback;
 };
 
 /** Global log informations */
@@ -236,8 +240,8 @@ int rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
  *   - 0: Success.
  *   - Negative on error.
  */
-int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
-	__attribute__((format(printf,3,0)));
+void rte_set_custom_vlog(rte_vlog_func_t callback);
+
 
 /**
  * Generates a log message.
diff --git a/lib/librte_eal/linuxapp/eal/eal_debug.c b/lib/librte_eal/linuxapp/eal/eal_debug.c
index 5fbc17c..f411d96 100644
--- a/lib/librte_eal/linuxapp/eal/eal_debug.c
+++ b/lib/librte_eal/linuxapp/eal/eal_debug.c
@@ -78,9 +78,16 @@ void __rte_panic(const char *funcname, const char *format, ...)
 	va_list ap;
 
 	rte_log(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, "PANIC in %s():\n", funcname);
+
+#define LOG_BUFFER_SIZE			4095
+static char log_buffer[LOG_BUFFER_SIZE+1];
+
 	va_start(ap, format);
-	rte_vlog(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, format, ap);
+	vsnprintf(log_buffer, LOG_BUFFER_SIZE, format, ap);
 	va_end(ap);
+
+	rte_logs.log_callback(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, log_buffer);
+
 	rte_dump_stack();
 	rte_dump_registers();
 	abort();
@@ -99,10 +106,15 @@ rte_exit(int exit_code, const char *format, ...)
 		RTE_LOG(CRIT, EAL, "Error - exiting with code: %d\n"
 				"  Cause: ", exit_code);
 
+#define LOG_BUFFER_SIZE			4095
+static char log_buffer[LOG_BUFFER_SIZE+1];
+
 	va_start(ap, format);
-	rte_vlog(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, format, ap);
+	vsnprintf(log_buffer, LOG_BUFFER_SIZE, format, ap);
 	va_end(ap);
 
+	rte_logs.log_callback(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, log_buffer);
+
 #ifndef RTE_EAL_ALWAYS_PANIC_ON_ERROR
 	exit(exit_code);
 #else
diff --git a/lib/librte_eal/linuxapp/eal/rte_eal_version.map b/lib/librte_eal/linuxapp/eal/rte_eal_version.map
index 83721ba..b35c8c3 100644
--- a/lib/librte_eal/linuxapp/eal/rte_eal_version.map
+++ b/lib/librte_eal/linuxapp/eal/rte_eal_version.map
@@ -94,6 +94,7 @@ DPDK_2.0 {
 	rte_openlog_stream;
 	rte_realloc;
 	rte_set_application_usage_hook;
+	rte_set_custom_vlog;
 	rte_set_log_level;
 	rte_set_log_type;
 	rte_socket_id;
@@ -102,7 +103,6 @@ DPDK_2.0 {
 	rte_sys_gettid;
 	rte_thread_get_affinity;
 	rte_thread_set_affinity;
-	rte_vlog;
 	rte_xen_dom0_memory_attach;
 	rte_xen_dom0_memory_init;
 	rte_zmalloc;
-- 
2.7.4