dpdk: Add commands to configure log levels.

Enabling debug logs in dpdk can be a challenge to be sure of what is
actually enabled, add commands to list and change those log levels.
However, these commands do not help when tracking issues in dpdk init
itself: dump log levels right after init.

Example:
$ ovs-appctl dpdk/log-list
global log level is debug
id 0: lib.eal, level is info
id 1: lib.malloc, level is info
id 2: lib.ring, level is info
id 3: lib.mempool, level is info
id 4: lib.timer, level is info
id 5: pmd, level is info
[...]
id 37: pmd.net.bnxt.driver, level is notice
id 38: pmd.net.e1000.init, level is notice
id 39: pmd.net.e1000.driver, level is notice
id 40: pmd.net.enic, level is info
[...]

$ ovs-appctl dpdk/log-set debug pmd.*:notice
$ ovs-appctl dpdk/log-list
global log level is debug
id 0: lib.eal, level is debug
id 1: lib.malloc, level is debug
id 2: lib.ring, level is debug
id 3: lib.mempool, level is debug
id 4: lib.timer, level is debug
id 5: pmd, level is debug
[...]
id 37: pmd.net.bnxt.driver, level is notice
id 38: pmd.net.e1000.init, level is notice
id 39: pmd.net.e1000.driver, level is notice
id 40: pmd.net.enic, level is notice
[...]

Signed-off-by: David Marchand <david.marchand@redhat.com>
Signed-off-by: Ilya Maximets <i.maximets@ovn.org>

NEWS

@@ -16,6 +16,8 @@ Post-v2.13.0
      * OVS validated with DPDK 19.11.2, due to the inclusion of fixes for
        CVE-2020-10722, CVE-2020-10723, CVE-2020-10724, CVE-2020-10725 and
        CVE-2020-10726, this DPDK version is strongly recommended to be used.
+     * New 'ovs-appctl dpdk/log-list' and 'ovs-appctl dpdk/log-set' commands
+       to list and change log levels in DPDK components.
    - Linux datapath:
      * Support for kernel versions up to 5.5.x.
    - AF_XDP:

lib/automake.mk

@@ -543,6 +543,7 @@ MAN_FRAGMENTS += \
 	lib/daemon-syn.man \
 	lib/db-ctl-base.man \
 	lib/dpctl.man \
+	lib/dpdk-unixctl.man \
 	lib/memory-unixctl.man \
 	lib/netdev-dpdk-unixctl.man \
 	lib/dpif-netdev-unixctl.man \

lib/dpdk-unixctl.man

@@ -0,0 +1,14 @@
+.SS "DPDK COMMANDS"
+These commands manage DPDK components.
+.IP "\fBdpdk/log-list\fR"
+Lists all DPDK components that emit logs and their logging levels.
+.IP "\fBdpdk/log-set\fR [\fIspec\fR]"
+Sets DPDK components logging level. Without any \fIspec\fR, sets the logging
+\fBlevel\fR for all DPDK components to \fBdebug\fR. Otherwise, \fIspec\fR is a
+list of words separated by spaces: a word can be either a logging \fBlevel\fR
+(\fBemergency\fR, \fBalert\fR, \fBcritical\fR, \fBerror\fR, \fBwarning\fR,
+\fBnotice\fR, \fBinfo\fR or \fBdebug\fR) or a \fBpattern\fR matching DPDK
+components (see \fBdpdk/log-list\fR command on \fBovs\-appctl\fR(8)) separated
+by a colon from the logging \fBlevel\fR to apply.
+.RE
+.

lib/dpdk.c

@@ -37,6 +37,7 @@
 #include "ovs-numa.h"
 #include "smap.h"
 #include "svec.h"
+#include "unixctl.h"
 #include "util.h"
 #include "vswitch-idl.h"
 
@@ -262,6 +263,99 @@ static cookie_io_functions_t dpdk_log_func = {
     .write = dpdk_log_write,
 };
 
+static void
+dpdk_unixctl_mem_stream(struct unixctl_conn *conn, int argc OVS_UNUSED,
+                        const char *argv[] OVS_UNUSED, void *aux)
+{
+    void (*callback)(FILE *) = aux;
+    char *response = NULL;
+    FILE *stream;
+    size_t size;
+
+    stream = open_memstream(&response, &size);
+    if (!stream) {
+        response = xasprintf("Unable to open memstream: %s.",
+                             ovs_strerror(errno));
+        unixctl_command_reply_error(conn, response);
+        goto out;
+    }
+
+    callback(stream);
+    fclose(stream);
+    unixctl_command_reply(conn, response);
+out:
+    free(response);
+}
+
+static int
+dpdk_parse_log_level(const char *s)
+{
+    static const char * const levels[] = {
+        [RTE_LOG_EMERG]   = "emergency",
+        [RTE_LOG_ALERT]   = "alert",
+        [RTE_LOG_CRIT]    = "critical",
+        [RTE_LOG_ERR]     = "error",
+        [RTE_LOG_WARNING] = "warning",
+        [RTE_LOG_NOTICE]  = "notice",
+        [RTE_LOG_INFO]    = "info",
+        [RTE_LOG_DEBUG]   = "debug",
+    };
+    int i;
+
+    for (i = 1; i < ARRAY_SIZE(levels); ++i) {
+        if (!strcmp(s, levels[i])) {
+            return i;
+        }
+    }
+    return -1;
+}
+
+static void
+dpdk_unixctl_log_set(struct unixctl_conn *conn, int argc, const char *argv[],
+                     void *aux OVS_UNUSED)
+{
+    int i;
+
+    /* With no argument, set all components level to 'debug'. */
+    if (argc == 1) {
+        rte_log_set_level_pattern("*", RTE_LOG_DEBUG);
+    }
+    for (i = 1; i < argc; i++) {
+        char *err_msg = NULL;
+        char *level_string;
+        char *pattern;
+        char *s;
+        int level;
+
+        s = xstrdup(argv[i]);
+        level_string = strchr(s, ':');
+        if (level_string == NULL) {
+            pattern = "*";
+            level_string = s;
+        } else {
+            pattern = s;
+            level_string[0] = '\0';
+            level_string++;
+        }
+
+        level = dpdk_parse_log_level(level_string);
+        if (level == -1) {
+            err_msg = xasprintf("invalid log level: '%s'", level_string);
+        } else if (rte_log_set_level_pattern(pattern, level) < 0) {
+            err_msg = xasprintf("cannot set log level for '%s'", argv[i]);
+        }
+
+        if (err_msg) {
+            unixctl_command_reply_error(conn, err_msg);
+            free(err_msg);
+            free(s);
+            return;
+        }
+        free(s);
+    }
+    unixctl_command_reply(conn, NULL);
+}
+
 static bool
 dpdk_init__(const struct smap *ovs_other_config)
 {
@@ -414,18 +508,24 @@ dpdk_init__(const struct smap *ovs_other_config)
         FILE *stream = open_memstream(&response, &size);
 
         if (stream) {
+            fprintf(stream, "rte_memzone_dump:\n");
             rte_memzone_dump(stream);
+            fprintf(stream, "rte_log_dump:\n");
+            rte_log_dump(stream);
             fclose(stream);
-            if (size) {
-                VLOG_DBG("rte_memzone_dump:\n%s", response);
-            }
+            VLOG_DBG("%s", response);
             free(response);
         } else {
-            VLOG_DBG("Could not dump memzone. Unable to open memstream: %s.",
-                     ovs_strerror(errno));
+            VLOG_DBG("Could not dump memzone and log levels. "
+                     "Unable to open memstream: %s.", ovs_strerror(errno));
         }
     }
 
+    unixctl_command_register("dpdk/log-list", "", 0, 0,
+                             dpdk_unixctl_mem_stream, rte_log_dump);
+    unixctl_command_register("dpdk/log-set", "{level | pattern:level}", 0,
+                             INT_MAX, dpdk_unixctl_log_set, NULL);
+
     /* We are called from the main thread here */
     RTE_PER_LCORE(_lcore_id) = NON_PMD_CORE_ID;
 

vswitchd/ovs-vswitchd.8.in

@@ -272,6 +272,7 @@ type).
 ..
 .so lib/dpctl.man
 .
+.so lib/dpdk-unixctl.man
 .so lib/dpif-netdev-unixctl.man
 .so lib/netdev-dpdk-unixctl.man
 .so ofproto/ofproto-dpif-unixctl.man