[RFC] log: track log level changes

Message ID 20200626114751.22523-1-david.marchand@redhat.com (mailing list archive)
State Superseded, archived
Delegated to: Thomas Monjalon
Headers
Series [RFC] log: track log level changes |

Checks

Context Check Description
ci/Intel-compilation success Compilation OK

Commit Message

David Marchand June 26, 2020, 11:47 a.m. UTC
  Add a log message when changing log levels to be sure of which logtype
is enabled.

Suggested-by: Ilya Maximets <i.maximets@ovn.org>
Signed-off-by: David Marchand <david.marchand@redhat.com>
---
Sending this as a RFC, this makes it easier to notice the problem we have
lived with so far: shared library loading do not honor log levels set on
cmdline unless it uses rte_log_register_type_and_pick_level.

---
 lib/librte_eal/common/eal_common_log.c | 56 ++++++++++++++++----------
 1 file changed, 35 insertions(+), 21 deletions(-)
  

Comments

Andrew Rybchenko June 26, 2020, 2:46 p.m. UTC | #1
On 6/26/20 2:47 PM, David Marchand wrote:
> Add a log message when changing log levels to be sure of which logtype
> is enabled.
> 
> Suggested-by: Ilya Maximets <i.maximets@ovn.org>
> Signed-off-by: David Marchand <david.marchand@redhat.com>

Acked-by: Andrew Rybchenko <arybchenko@solarflare.com>
  
Lukasz Wojciechowski July 9, 2020, 12:16 a.m. UTC | #2
W dniu 26.06.2020 o 16:46, Andrew Rybchenko pisze:
> On 6/26/20 2:47 PM, David Marchand wrote:
>> Add a log message when changing log levels to be sure of which logtype
>> is enabled.
>>
>> Suggested-by: Ilya Maximets <i.maximets@ovn.org>
>> Signed-off-by: David Marchand <david.marchand@redhat.com>
> Acked-by: Andrew Rybchenko <arybchenko@solarflare.com>
>
I also like the idea so:

Acked-by: Lukasz Wojciechowski <l.wojciechow@partner.samsung.com>

although I think there is one place that can be smoothed a bit. Every 
newly registered type's loglevel is set to RTE_LOG_INFO in 
__rte_log_register(), so:
* if new type is registered with rte_log_register_type_and_pick_level() 
and level is set to INFO, nothing will be printed (as current is equal 
to new level);
* any registration made with rte_log_register() won't be seen either as 
there is no call to newly introduced function logtype_set_level().

How about additionally changing behavior so any registration will print 
change from "disabled" (level=0) to new level:
* in case of rte_log_register_type_and_pick_level() to chosen level
* in case of rte_log_register() to default level which is "info"

Best regards
  
David Marchand March 23, 2021, 8:19 a.m. UTC | #3
Hello Lukasz,

On Thu, Jul 9, 2020 at 2:16 AM Lukasz Wojciechowski
<l.wojciechow@partner.samsung.com> wrote:
>
>
> W dniu 26.06.2020 o 16:46, Andrew Rybchenko pisze:
> > On 6/26/20 2:47 PM, David Marchand wrote:
> >> Add a log message when changing log levels to be sure of which logtype
> >> is enabled.
> >>
>
> although I think there is one place that can be smoothed a bit. Every
> newly registered type's loglevel is set to RTE_LOG_INFO in
> __rte_log_register(), so:
> * if new type is registered with rte_log_register_type_and_pick_level()
> and level is set to INFO, nothing will be printed (as current is equal
> to new level);
> * any registration made with rte_log_register() won't be seen either as
> there is no call to newly introduced function logtype_set_level().
>
> How about additionally changing behavior so any registration will print
> change from "disabled" (level=0) to new level:
> * in case of rte_log_register_type_and_pick_level() to chosen level
> * in case of rte_log_register() to default level which is "info"

Sorry, I had forgotten about this rfc... reviving it as I am reviewing
some log patch.
Good idea, I will post a v1 with this.
  

Patch

diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
index 8835c8fff8..24d53ed9c7 100644
--- a/lib/librte_eal/common/eal_common_log.c
+++ b/lib/librte_eal/common/eal_common_log.c
@@ -130,6 +130,37 @@  rte_log_can_log(uint32_t logtype, uint32_t level)
 	return true;
 }
 
+static const char *
+loglevel_to_string(uint32_t level)
+{
+	switch (level) {
+	case 0: return "disabled";
+	case RTE_LOG_EMERG: return "emerg";
+	case RTE_LOG_ALERT: return "alert";
+	case RTE_LOG_CRIT: return "critical";
+	case RTE_LOG_ERR: return "error";
+	case RTE_LOG_WARNING: return "warning";
+	case RTE_LOG_NOTICE: return "notice";
+	case RTE_LOG_INFO: return "info";
+	case RTE_LOG_DEBUG: return "debug";
+	default: return "unknown";
+	}
+}
+
+static void
+logtype_set_level(uint32_t type, uint32_t level)
+{
+	uint32_t current = rte_logs.dynamic_types[type].loglevel;
+
+	if (current != level) {
+		rte_logs.dynamic_types[type].loglevel = level;
+		RTE_LOG(DEBUG, EAL, "%s logtype level changed from %s to %s\n",
+			rte_logs.dynamic_types[type].name,
+			loglevel_to_string(current),
+			loglevel_to_string(level));
+	}
+}
+
 int
 rte_log_set_level(uint32_t type, uint32_t level)
 {
@@ -138,7 +169,7 @@  rte_log_set_level(uint32_t type, uint32_t level)
 	if (level > RTE_LOG_DEBUG)
 		return -1;
 
-	rte_logs.dynamic_types[type].loglevel = level;
+	logtype_set_level(type, level);
 
 	return 0;
 }
@@ -161,7 +192,7 @@  rte_log_set_level_regexp(const char *regex, uint32_t level)
 			continue;
 		if (regexec(&r, rte_logs.dynamic_types[i].name, 0,
 				NULL, 0) == 0)
-			rte_logs.dynamic_types[i].loglevel = level;
+			logtype_set_level(i, level);
 	}
 
 	regfree(&r);
@@ -221,7 +252,7 @@  rte_log_set_level_pattern(const char *pattern, uint32_t level)
 			continue;
 
 		if (fnmatch(pattern, rte_logs.dynamic_types[i].name, 0) == 0)
-			rte_logs.dynamic_types[i].loglevel = level;
+			logtype_set_level(i, level);
 	}
 
 	return 0;
@@ -328,7 +359,7 @@  rte_log_register_type_and_pick_level(const char *name, uint32_t level_def)
 		}
 	}
 
-	rte_logs.dynamic_types[type].loglevel = level;
+	logtype_set_level(type, level);
 
 	return type;
 }
@@ -390,23 +421,6 @@  RTE_INIT_PRIO(rte_log_init, LOG)
 	rte_logs.dynamic_types_len = RTE_LOGTYPE_FIRST_EXT_ID;
 }
 
-static const char *
-loglevel_to_string(uint32_t level)
-{
-	switch (level) {
-	case 0: return "disabled";
-	case RTE_LOG_EMERG: return "emerg";
-	case RTE_LOG_ALERT: return "alert";
-	case RTE_LOG_CRIT: return "critical";
-	case RTE_LOG_ERR: return "error";
-	case RTE_LOG_WARNING: return "warning";
-	case RTE_LOG_NOTICE: return "notice";
-	case RTE_LOG_INFO: return "info";
-	case RTE_LOG_DEBUG: return "debug";
-	default: return "unknown";
-	}
-}
-
 /* dump global level and registered log types */
 void
 rte_log_dump(FILE *f)