Skip to contentSkip to conversation

librte_eal: allow wider range of log levels

PATCH In review Matthew Hall 5 participants 17 messages Nov 13, 2015

lore
Share & tools
lore
#0 lore raw

cover librte_eal: allow wider range of log levels

This is a simple but very helpful patch for app developers. It allows a wider range of log levels from in the rte_log framework.

It allows developers to avoid resorting to a lot of external log frameworks in their DPDK code.

Matthew Hall (6):
librte_log: add function to retrieve log_level rte_log.h: add detailed log levels RTE_LOG{FINE,FINER,FINEST} eal_common_log.c: reset default level to RTE_LOG_FINEST rte_log.h: update logging docs to include FINEST level rte_log.h: add RTE_SYSLOG_LEVEL_MAX
eal_log.c: limit syslog level to RTE_SYSLOG_LEVEL_MAX

 lib/librte_eal/common/eal_common_log.c  |  2 +-
 lib/librte_eal/common/include/rte_log.h | 31 +++++++++++++++++++------------
 lib/librte_eal/linuxapp/eal/eal_log.c   |  1 +
 3 files changed, 21 insertions(+), 13 deletions(-)
Signature · 1 line
1.9.1
#1 lore raw

PATCH 1/6 librte_log: add function to retrieve log_level

---
 lib/librte_eal/common/include/rte_log.h | 1 +
 1 file changed, 1 insertion(+)
lib/librte_eal/common/include/rte_log.h +1 -0
index ede0dca..9dad24e 100644
@@ -131,6 +131,7 @@ void rte_set_log_level(uint32_t level);
 
 /**
  * Get the global log level.
+ *
  */
 uint32_t rte_get_log_level(void);
 
Signature · 1 line
1.9.1
#2 lore raw

Re: [PATCH 1/6] librte_log: add function to retrieve log_level

Quoted 20 lines · Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 1 +
 1 file changed, 1 insertion(+)
lib/librte_eal/common/include/rte_log.h +1 -0
index ede0dca..9dad24e 100644
@@ -131,6 +131,7 @@ void rte_set_log_level(uint32_t level);
 
 /**
  * Get the global log level.
+ *
  */
 uint32_t rte_get_log_level(void);
 
Signature · 1 line
1.9.1

I don't think this patch is necessary, as all it adds is a single extra line to a comment.

/Bruce

#3 lore raw

Re: [PATCH 1/6] librte_log: add function to retrieve log_level

2015-11-13 11:40, Bruce Richardson:

Quoted 5 lines · Matthew Hall
Quoted 4 lines
lib/librte_eal/common/include/rte_log.h +0 -0
@@ -131,6 +131,7 @@ void rte_set_log_level(uint32_t level);
 
Quoted 8 lines

lib/librte_eal/common/include/rte_log.h void rte_set_log_level(uint32_t level); · line 137

Quoted 6 lines
lib/librte_eal/common/include/rte_log.h +1 -0
 /**
  * Get the global log level.
+ *
  */
 uint32_t rte_get_log_level(void);
 

I don't think this patch is necessary, as all it adds is a single extra line to a comment.

I'm sad for you Bruce: you only see an empty line where you could catch the beauty of the star ;)

Matthew, obviously you failed your send.
As a general comment, please group patches by logic meaning and check them before sending ;)

#4 lore raw

Re: [PATCH 1/6] librte_log: add function to retrieve log_level

Quoted 2 lines · Thomas Monjalon

I'm sad for you Bruce: you only see an empty line where you could catch the beauty of the star ;)

+1

Quoted 1 line

Matthew, obviously you failed your send.

You might find a more polite way than calling contributions failures. ;)

Quoted 2 lines

As a general comment, please group patches by logic meaning and check them before sending ;)

I did. But I'm a community guy and this is not full-time employment, and I am admittedly quite bad at git email workflow and don't like it much as discussed in previous threads.

So I did the best I could do but screwed up something minor at approx 1 or 2 AM. It happens. I don't send you guys crazy emails when there is a build failure upstream either you know. (:

Matthew.

#5 lore raw

Re: [PATCH 1/6] librte_log: add function to retrieve log_level

In reply to Bruce Richardson
Quoted 4 lines · Bruce Richardson

I don't think this patch is necessary, as all it adds is a single extra line to a comment.

/Bruce

This one was previously merged. So indeed we can toss it.

This is what happens when you are restricted to 1 AM coding.

Matthew.

#6 lore raw

PATCH 2/6 rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

In reply to Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)
lib/librte_eal/common/include/rte_log.h +11 -8
index 9dad24e..7dc19e1 100644
@@ -90,14 +90,17 @@ extern struct rte_logs rte_logs;
 #define RTE_LOGTYPE_USER8   0x80000000 /**< User-defined log type 8. */
 
 /* Can't use 0, as it gives compiler warnings */
-#define RTE_LOG_EMERG    1U  /**< System is unusable.               */
-#define RTE_LOG_ALERT    2U  /**< Action must be taken immediately. */
-#define RTE_LOG_CRIT     3U  /**< Critical conditions.              */
-#define RTE_LOG_ERR      4U  /**< Error conditions.                 */
-#define RTE_LOG_WARNING  5U  /**< Warning conditions.               */
-#define RTE_LOG_NOTICE   6U  /**< Normal but significant condition. */
-#define RTE_LOG_INFO     7U  /**< Informational.                    */
-#define RTE_LOG_DEBUG    8U  /**< Debug-level messages.             */
+#define RTE_LOG_EMERG     1U  /**< System is unusable.               */
+#define RTE_LOG_ALERT     2U  /**< Action must be taken immediately. */
+#define RTE_LOG_CRIT      3U  /**< Critical conditions.              */
+#define RTE_LOG_ERR       4U  /**< Error conditions.                 */
+#define RTE_LOG_WARNING   5U  /**< Warning conditions.               */
+#define RTE_LOG_NOTICE    6U  /**< Normal but significant condition. */
+#define RTE_LOG_INFO      7U  /**< Informational.                    */
+#define RTE_LOG_DEBUG     8U  /**< Debug-level messages.             */
+#define RTE_LOG_FINE      9U  /**< Fine-level messages.              */
+#define RTE_LOG_FINER    10U  /**< Finer-level messages.             */
+#define RTE_LOG_FINEST   11U  /**< Finest-level messages.            */
 
 /** The default log stream. */
 extern FILE *eal_default_log_stream;
Signature · 1 line
1.9.1
#7 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

Quoted 38 lines · Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)
lib/librte_eal/common/include/rte_log.h +11 -8
index 9dad24e..7dc19e1 100644
@@ -90,14 +90,17 @@ extern struct rte_logs rte_logs;
 #define RTE_LOGTYPE_USER8   0x80000000 /**< User-defined log type 8. */
 
 /* Can't use 0, as it gives compiler warnings */
-#define RTE_LOG_EMERG    1U  /**< System is unusable.               */
-#define RTE_LOG_ALERT    2U  /**< Action must be taken immediately. */
-#define RTE_LOG_CRIT     3U  /**< Critical conditions.              */
-#define RTE_LOG_ERR      4U  /**< Error conditions.                 */
-#define RTE_LOG_WARNING  5U  /**< Warning conditions.               */
-#define RTE_LOG_NOTICE   6U  /**< Normal but significant condition. */
-#define RTE_LOG_INFO     7U  /**< Informational.                    */
-#define RTE_LOG_DEBUG    8U  /**< Debug-level messages.             */
+#define RTE_LOG_EMERG     1U  /**< System is unusable.               */
+#define RTE_LOG_ALERT     2U  /**< Action must be taken immediately. */
+#define RTE_LOG_CRIT      3U  /**< Critical conditions.              */
+#define RTE_LOG_ERR       4U  /**< Error conditions.                 */
+#define RTE_LOG_WARNING   5U  /**< Warning conditions.               */
+#define RTE_LOG_NOTICE    6U  /**< Normal but significant condition. */
+#define RTE_LOG_INFO      7U  /**< Informational.                    */
+#define RTE_LOG_DEBUG     8U  /**< Debug-level messages.             */
+#define RTE_LOG_FINE      9U  /**< Fine-level messages.              */
+#define RTE_LOG_FINER    10U  /**< Finer-level messages.             */
+#define RTE_LOG_FINEST   11U  /**< Finest-level messages.            */
 
 /** The default log stream. */
 extern FILE *eal_default_log_stream;
Signature · 1 line
1.9.1

Why 11 log levels - it seems an odd number?
Also, not sure about the {fine, finer, finest} names. My thinking would be to just start numbering them after DEBUG, so RTE_LOG_L9, RTE_LOG_L10 etc., which would allow us to add on an arbitrary number of extra log levels as needed.

/Bruce

#8 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

Quoted 43 lines

-----Original Message-----
From: dev [mailto:[email protected]] On Behalf Of Bruce Richardson
Sent: Friday, November 13, 2015 11:44 AM
To: Matthew Hall
Cc: [email protected]
Subject: Re: [dpdk-dev] [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

Quoted 33 lines · Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)
lib/librte_eal/common/include/rte_log.h +11 -8
index 9dad24e..7dc19e1 100644
@@ -90,14 +90,17 @@ extern struct rte_logs rte_logs;
 #define RTE_LOGTYPE_USER8   0x80000000 /**< User-defined log type 8. */
 
 /* Can't use 0, as it gives compiler warnings */
-#define RTE_LOG_EMERG    1U  /**< System is unusable.               */
-#define RTE_LOG_ALERT    2U  /**< Action must be taken immediately. */
-#define RTE_LOG_CRIT     3U  /**< Critical conditions.              */
-#define RTE_LOG_ERR      4U  /**< Error conditions.                 */
-#define RTE_LOG_WARNING  5U  /**< Warning conditions.               */
-#define RTE_LOG_NOTICE   6U  /**< Normal but significant condition. */
-#define RTE_LOG_INFO     7U  /**< Informational.                    */
-#define RTE_LOG_DEBUG    8U  /**< Debug-level messages.             */
+#define RTE_LOG_EMERG     1U  /**< System is unusable.               */
+#define RTE_LOG_ALERT     2U  /**< Action must be taken immediately. */
+#define RTE_LOG_CRIT      3U  /**< Critical conditions.              */
+#define RTE_LOG_ERR       4U  /**< Error conditions.                 */
+#define RTE_LOG_WARNING   5U  /**< Warning conditions.               */
+#define RTE_LOG_NOTICE    6U  /**< Normal but significant condition. */
+#define RTE_LOG_INFO      7U  /**< Informational.                    */
+#define RTE_LOG_DEBUG     8U  /**< Debug-level messages.             */
+#define RTE_LOG_FINE      9U  /**< Fine-level messages.              */
+#define RTE_LOG_FINER    10U  /**< Finer-level messages.             */
+#define RTE_LOG_FINEST   11U  /**< Finest-level messages.            */
 
Quoted 9 lines
Quoted 5 lines
lib/librte_eal/common/include/rte_log.h +0 -1
 /** The default log stream. */
 extern FILE *eal_default_log_stream;
--

1.9.1

Why 11 log levels - it seems an odd number?
Also, not sure about the {fine, finer, finest} names. My thinking would be to just start numbering them after DEBUG, so RTE_LOG_L9, RTE_LOG_L10 etc., which would allow us to add on an arbitrary number of extra log levels as needed.

Actually another question: are existing 8 levels not enough? Konstantin

Quoted 2 lines

/Bruce

#9 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

Quoted 2 lines · Konstantin

Actually another question: are existing 8 levels not enough? Konstantin

Depends who you ask. I was modeling it based upon the following:

https://docs.oracle.com/javase/7/docs/api/java/util/logging/Level.html

The reason I added a previously-merged patch for a new function rte_get_log_level() and all these extra levels is that it allows me to do crazy stuff like this:

    if (rte_get_log_level() >= RTE_LOG_FINEST) {
        rte_hexdump(stderr, "header_bytes", packet->header.bytes, packet->header.header_size);
    }

It is extremely valuable to have levels which go below INFO, so you can make detailed trace code compiled directly into your app. Which can be readily enabled or disabled by setting the log_level. WAY easier to debug the early green-field code in your app when it crashes somehow.

Obviously the first thing you guys will say is... "BUT THAT RUNS WAY TOO SLOW!!!!!" and you might be right if you are processing 100 gbits/sec. But I am using DPDK for security not for SDN switching or core routing. And my patch will not introduce any performance change for the guys doing the other stuff either.

So if this patch is not accepted in some form, I'd be stuck with my DPDK fork just for this feature, and the pre-existing patches I sent to Bruce & Co. regarding rte_lpm and rte_lpm6 expansion and so on.

Matthew.

#10 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

In reply to Bruce Richardson
Quoted 6 lines · Bruce Richardson

Why 11 log levels - it seems an odd number?
Also, not sure about the {fine, finer, finest} names. My thinking would be to just start numbering them after DEBUG, so RTE_LOG_L9, RTE_LOG_L10 etc., which would allow us to add on an arbitrary number of extra log levels as needed.

/Bruce

I based it on this, it worked very well for me in the past.

https://docs.oracle.com/javase/7/docs/api/java/util/logging/Level.html

But happy to name them anything people want and have any number of them people want. I am not religious about the details, just want the feature.

Matthew.

#11 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

In reply to Matthew Hall
Quoted 25 lines · On Fri, 13 Nov 2015 06:47:34 +0000 Matthew Hall <[email protected]> wrote:
---
 lib/librte_eal/common/include/rte_log.h | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)
lib/librte_eal/common/include/rte_log.h +4 -8
index 9dad24e..7dc19e1 100644
@@ -90,14 +90,17 @@ extern struct rte_logs rte_logs;
 #define RTE_LOGTYPE_USER8   0x80000000 /**< User-defined log type 8. */
 
 /* Can't use 0, as it gives compiler warnings */
-#define RTE_LOG_EMERG    1U  /**< System is unusable.               */
-#define RTE_LOG_ALERT    2U  /**< Action must be taken immediately. */
-#define RTE_LOG_CRIT     3U  /**< Critical conditions.              */
-#define RTE_LOG_ERR      4U  /**< Error conditions.                 */
-#define RTE_LOG_WARNING  5U  /**< Warning conditions.               */
-#define RTE_LOG_NOTICE   6U  /**< Normal but significant condition. */
-#define RTE_LOG_INFO     7U  /**< Informational.                    */
-#define RTE_LOG_DEBUG    8U  /**< Debug-level messages.             */
+#define RTE_LOG_EMERG     1U  /**< System is unusable.               */
+#define RTE_LOG_ALERT     2U  /**< Action must be taken immediately. */
+#define RTE_LOG_CRIT      3U  /**< Critical conditions.              */
+#define RTE_LOG_ERR       4U  /**< Error conditions.                 */

lib/librte_eal/common/include/rte_log.h extern struct rte_logs rte_logs; · line 106

Quoted 10 lines
lib/librte_eal/common/include/rte_log.h +7 -0
+#define RTE_LOG_WARNING   5U  /**< Warning conditions.               */
+#define RTE_LOG_NOTICE    6U  /**< Normal but significant condition. */
+#define RTE_LOG_INFO      7U  /**< Informational.                    */
+#define RTE_LOG_DEBUG     8U  /**< Debug-level messages.             */
+#define RTE_LOG_FINE      9U  /**< Fine-level messages.              */
+#define RTE_LOG_FINER    10U  /**< Finer-level messages.             */
+#define RTE_LOG_FINEST   11U  /**< Finest-level messages.            */
 
 /** The default log stream. */
 extern FILE *eal_default_log_stream;

I understand the motivation but the existing levels match syslog which are what you want for a production application.

The new levels are only for developer logs. I don't think we want all the developer levels beyond debug in the upstream tree anyway.

#12 lore raw

Re: [PATCH 2/6] rte_log.h: add detailed log levels RTE_LOG{FINE, FINER, FINEST}

Quoted 5 lines · Stephen Hemminger

I understand the motivation but the existing levels match syslog which are what you want for a production application.

The new levels are only for developer logs. I don't think we want all the developer levels beyond debug in the upstream tree anyway.

I figured everybody would say this.

So then I have to fork DPDK for a trivial aid to coders which doesn't affect performance.

This is silly to me.

Matthew.

#13 lore raw

PATCH 3/6 eal_common_log.c: reset default level to RTE_LOG_FINEST

In reply to Matthew Hall
---
 lib/librte_eal/common/eal_common_log.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
lib/librte_eal/common/eal_common_log.c +1 -1
index 1ae8de7..510eeff 100644
@@ -82,7 +82,7 @@ static struct log_history_list log_history;
 /* global log structure */
 struct rte_logs rte_logs = {
 	.type = ~0,
-	.level = RTE_LOG_DEBUG,
+	.level = RTE_LOG_FINEST,
 	.file = NULL,
 };
 
Signature · 1 line
1.9.1
#14 lore raw

PATCH 4/6 rte_log.h: update logging docs to include FINEST level

In reply to Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)
lib/librte_eal/common/include/rte_log.h +4 -4
index 7dc19e1..4a70ce5 100644
@@ -128,7 +128,7 @@ int rte_openlog_stream(FILE *f);
  * displayed.
  *
  * @param level
- *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
+ *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_FINEST (11).
  */
 void rte_set_log_level(uint32_t level);
 
@@ -228,7 +228,7 @@ int rte_log_add_in_history(const char *buf, size_t size);
  * logs are automatically prefixed by type when using the macro.
  *
  * @param level
- *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
+ *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_FINEST (11).
  * @param logtype
  *   The log type, for example, RTE_LOGTYPE_EAL.
  * @param format
@@ -260,7 +260,7 @@ int rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
  * removed at compilation time.
  *
  * @param level
- *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_DEBUG (8).
+ *   Log level. A value between RTE_LOG_EMERG (1) and RTE_LOG_FINEST (11).
  * @param logtype
  *   The log type, for example, RTE_LOGTYPE_EAL.
  * @param format
@@ -289,7 +289,7 @@ int rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
  *   RTE_LOG(INFO, EAL, "this is a %s", "log");
  *
  * @param l
- *   Log level. A value between EMERG (1) and DEBUG (8). The short name is
+ *   Log level. A value between EMERG (1) and FINEST (11). The short name is
  *   expanded by the macro, so it cannot be an integer value.
  * @param t
  *   The log type, for example, EAL. The short name is expanded by the
Signature · 1 line
1.9.1
#15 lore raw

PATCH 5/6 rte_log.h: add RTE_SYSLOG_LEVEL_MAX

In reply to Matthew Hall
---
 lib/librte_eal/common/include/rte_log.h | 3 +++
 1 file changed, 3 insertions(+)
lib/librte_eal/common/include/rte_log.h +3 -0
index 4a70ce5..d7e11f1 100644
@@ -102,6 +102,9 @@ extern struct rte_logs rte_logs;
 #define RTE_LOG_FINER    10U  /**< Finer-level messages.             */
 #define RTE_LOG_FINEST   11U  /**< Finest-level messages.            */
 
+/* Syslog only supports 7 (DEBUG) and higher levels. */
+#define RTE_SYSLOG_LEVEL_MAX 7U
+
 /** The default log stream. */
 extern FILE *eal_default_log_stream;
 
Signature · 1 line
1.9.1
#16 lore raw

PATCH 6/6 eal_log.c: limit syslog level to RTE_SYSLOG_LEVEL_MAX

In reply to Matthew Hall
---
 lib/librte_eal/linuxapp/eal/eal_log.c | 1 +
 1 file changed, 1 insertion(+)
lib/librte_eal/linuxapp/eal/eal_log.c +1 -0
index 0b133c3..dbeff75 100644
@@ -73,6 +73,7 @@ console_log_write(__attribute__((unused)) void *c, const char *buf, size_t size)
 
 	/* Syslog error levels are from 0 to 7, so subtract 1 to convert */
 	loglevel = rte_log_cur_msg_loglevel() - 1;
+	loglevel = loglevel > RTE_SYSLOG_LEVEL_MAX ? RTE_SYSLOG_LEVEL_MAX : loglevel;
 	memcpy(copybuf, buf, size);
 	copybuf[size] = '\0';
 
Signature · 1 line
1.9.1