[bitbake-devel] bitbake: msg: Add bb.warnonce() and bb.erroronce() log methods

Message ID 20220216154646.2499980-1-JPEWhacker@gmail.com
State New
Headers show
Series [bitbake-devel] bitbake: msg: Add bb.warnonce() and bb.erroronce() log methods | expand

Commit Message

Joshua Watt Feb. 16, 2022, 3:46 p.m. UTC
From: Richard Purdie <richard.purdie@linuxfoundation.org>

This adds a log level and logging function call to use it where the
warning or error will only be displayed once, regardless of how many
times the message is logged.

This has to be done either in the cooker or on the UI side. I've opted
for the UI side since display control is really a UI issue but it uses
a common library filter function to enable it which can be reused
elsewhere.

The knotty message displayed as the build summary is tweaked to
make sense when the numbers won't match since it will still count
the number of times it was logged and this is probably helpful
for debugging in some cases so I've deliberately left it that way.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
---
 bitbake/lib/bb/__init__.py  | 13 +++++++++++++
 bitbake/lib/bb/msg.py       | 32 +++++++++++++++++++++++++++++++-
 bitbake/lib/bb/ui/knotty.py | 14 +++++++-------
 3 files changed, 51 insertions(+), 8 deletions(-)

Comments

Christopher Larson Feb. 16, 2022, 4:18 p.m. UTC | #1
On Wed, Feb 16, 2022 at 8:47 AM Joshua Watt <JPEWhacker@gmail.com> wrote:

> From: Richard Purdie <richard.purdie@linuxfoundation.org>
>
> This adds a log level and logging function call to use it where the
> warning or error will only be displayed once, regardless of how many
> times the message is logged.
>

This looks really useful, I've had use cases for this on a whole lot of
occasions, so thanks much for your work on this, Richard!
Peter Kjellerstedt Feb. 16, 2022, 4:22 p.m. UTC | #2
> -----Original Message-----
> From: bitbake-devel@lists.openembedded.org <bitbake-
> devel@lists.openembedded.org> On Behalf Of Joshua Watt
> Sent: den 16 februari 2022 16:47
> To: bitbake-devel@lists.openembedded.org
> Cc: Richard Purdie <richard.purdie@linuxfoundation.org>; Joshua Watt
> <JPEWhacker@gmail.com>
> Subject: [bitbake-devel][PATCH] bitbake: msg: Add bb.warnonce() and
> bb.erroronce() log methods
> 
> From: Richard Purdie <richard.purdie@linuxfoundation.org>
> 
> This adds a log level and logging function call to use it where the
> warning or error will only be displayed once, regardless of how many
> times the message is logged.
> 
> This has to be done either in the cooker or on the UI side. I've opted
> for the UI side since display control is really a UI issue but it uses
> a common library filter function to enable it which can be reused
> elsewhere.
> 
> The knotty message displayed as the build summary is tweaked to
> make sense when the numbers won't match since it will still count
> the number of times it was logged and this is probably helpful
> for debugging in some cases so I've deliberately left it that way.
> 
> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
> Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
> ---
>  bitbake/lib/bb/__init__.py  | 13 +++++++++++++
>  bitbake/lib/bb/msg.py       | 32 +++++++++++++++++++++++++++++++-
>  bitbake/lib/bb/ui/knotty.py | 14 +++++++-------
>  3 files changed, 51 insertions(+), 8 deletions(-)

[cut]

> diff --git a/bitbake/lib/bb/msg.py b/bitbake/lib/bb/msg.py
> index 291b38ff7f..512ec1f5c1 100644
> --- a/bitbake/lib/bb/msg.py
> +++ b/bitbake/lib/bb/msg.py
> @@ -30,7 +30,9 @@ class BBLogFormatter(logging.Formatter):
>      PLAIN = logging.INFO + 1
>      VERBNOTE = logging.INFO + 2
>      ERROR = logging.ERROR
> +    ERRORONCE = logging.ERROR - 1
>      WARNING = logging.WARNING
> +    WARNONCE = logging.WARNING - 1
>      CRITICAL = logging.CRITICAL
> 
>      levelnames = {
> @@ -42,7 +44,9 @@ class BBLogFormatter(logging.Formatter):
>          PLAIN  : '',
>          VERBNOTE: 'NOTE',
>          WARNING : 'WARNING',
> +        WARNONCE : 'WARNING',
>          ERROR   : 'ERROR',
> +        ERRORONCE   : 'ERROR',
>          CRITICAL: 'ERROR',
>      }
> 
> @@ -58,7 +62,9 @@ class BBLogFormatter(logging.Formatter):
>          PLAIN   : BASECOLOR,
>          VERBNOTE: BASECOLOR,
>          WARNING : YELLOW,
> +        WARNONCE : YELLOW,
>          ERROR   : RED,
> +        ERRORONCE : RED,
>          CRITICAL: RED,
>      }
> 

A qualified guess is that those colons above were once expected to 
line up...


//Peter

Patch

diff --git a/bitbake/lib/bb/__init__.py b/bitbake/lib/bb/__init__.py
index e01b8d5256..269f65edce 100644
--- a/bitbake/lib/bb/__init__.py
+++ b/bitbake/lib/bb/__init__.py
@@ -71,6 +71,13 @@  class BBLoggerMixin(object):
     def verbnote(self, msg, *args, **kwargs):
         return self.log(logging.INFO + 2, msg, *args, **kwargs)
 
+    def warnonce(self, msg, *args, **kwargs):
+        return self.log(logging.WARNING - 1, msg, *args, **kwargs)
+
+    def erroronce(self, msg, *args, **kwargs):
+        return self.log(logging.ERROR - 1, msg, *args, **kwargs)
+
+
 Logger = logging.getLoggerClass()
 class BBLogger(Logger, BBLoggerMixin):
     def __init__(self, name, *args, **kwargs):
@@ -157,9 +164,15 @@  def verbnote(*args):
 def warn(*args):
     mainlogger.warning(''.join(args))
 
+def warnonce(*args):
+    mainlogger.warnonce(''.join(args))
+
 def error(*args, **kwargs):
     mainlogger.error(''.join(args), extra=kwargs)
 
+def erroronce(*args):
+    mainlogger.erroronce(''.join(args))
+
 def fatal(*args, **kwargs):
     mainlogger.critical(''.join(args), extra=kwargs)
     raise BBHandledException()
diff --git a/bitbake/lib/bb/msg.py b/bitbake/lib/bb/msg.py
index 291b38ff7f..512ec1f5c1 100644
--- a/bitbake/lib/bb/msg.py
+++ b/bitbake/lib/bb/msg.py
@@ -30,7 +30,9 @@  class BBLogFormatter(logging.Formatter):
     PLAIN = logging.INFO + 1
     VERBNOTE = logging.INFO + 2
     ERROR = logging.ERROR
+    ERRORONCE = logging.ERROR - 1
     WARNING = logging.WARNING
+    WARNONCE = logging.WARNING - 1
     CRITICAL = logging.CRITICAL
 
     levelnames = {
@@ -42,7 +44,9 @@  class BBLogFormatter(logging.Formatter):
         PLAIN  : '',
         VERBNOTE: 'NOTE',
         WARNING : 'WARNING',
+        WARNONCE : 'WARNING',
         ERROR   : 'ERROR',
+        ERRORONCE   : 'ERROR',
         CRITICAL: 'ERROR',
     }
 
@@ -58,7 +62,9 @@  class BBLogFormatter(logging.Formatter):
         PLAIN   : BASECOLOR,
         VERBNOTE: BASECOLOR,
         WARNING : YELLOW,
+        WARNONCE : YELLOW,
         ERROR   : RED,
+        ERRORONCE : RED,
         CRITICAL: RED,
     }
 
@@ -121,6 +127,23 @@  class BBLogFilter(object):
             return True
         return False
 
+class LogFilterShowOnce(logging.Filter):
+    def __init__(self):
+        self.seen_warnings = set()
+        self.seen_errors = set()
+
+    def filter(self, record):
+        msg = record.msg
+        if record.levelno == bb.msg.BBLogFormatter.WARNONCE:
+            if record.msg in self.seen_warnings:
+                return False
+            self.seen_warnings.add(record.msg)
+        if record.levelno == bb.msg.BBLogFormatter.ERRORONCE:
+            if record.msg in self.seen_errors:
+                return False
+            self.seen_errors.add(record.msg)
+        return True
+
 class LogFilterGEQLevel(logging.Filter):
     def __init__(self, level):
         self.strlevel = str(level)
@@ -293,10 +316,17 @@  def setLoggingConfig(defaultconfig, userconfigfile=None):
 
     # Convert all level parameters to integers in case users want to use the
     # bitbake defined level names
-    for h in logconfig["handlers"].values():
+    for name, h in logconfig["handlers"].items():
         if "level" in h:
             h["level"] = bb.msg.stringToLevel(h["level"])
 
+        # Every handler needs its own instance of the once filter.
+        once_filter_name = name + ".showonceFilter"
+        logconfig.setdefault("filters", {})[once_filter_name] = {
+            "()": "bb.msg.LogFilterShowOnce",
+        }
+        h.setdefault("filters", []).append(once_filter_name)
+
     for l in logconfig["loggers"].values():
         if "level" in l:
             l["level"] = bb.msg.stringToLevel(l["level"])
diff --git a/bitbake/lib/bb/ui/knotty.py b/bitbake/lib/bb/ui/knotty.py
index d6f95fb17d..528b8a0760 100644
--- a/bitbake/lib/bb/ui/knotty.py
+++ b/bitbake/lib/bb/ui/knotty.py
@@ -647,7 +647,7 @@  def main(server, eventHandler, params, tf = TerminalFilter):
             if isinstance(event, logging.LogRecord):
                 lastprint = time.time()
                 printinterval = 5000
-                if event.levelno >= bb.msg.BBLogFormatter.ERROR:
+                if event.levelno >= bb.msg.BBLogFormatter.ERRORONCE:
                     errors = errors + 1
                     return_value = 1
                 elif event.levelno == bb.msg.BBLogFormatter.WARNING:
@@ -661,10 +661,10 @@  def main(server, eventHandler, params, tf = TerminalFilter):
                         continue
 
                     # Prefix task messages with recipe/task
-                    if event.taskpid in helper.pidmap and event.levelno != bb.msg.BBLogFormatter.PLAIN:
+                    if event.taskpid in helper.pidmap and event.levelno not in [bb.msg.BBLogFormatter.PLAIN, bb.msg.BBLogFormatter.WARNONCE, bb.msg.BBLogFormatter.ERRORONCE]:
                         taskinfo = helper.running_tasks[helper.pidmap[event.taskpid]]
                         event.msg = taskinfo['title'] + ': ' + event.msg
-                if hasattr(event, 'fn'):
+                if hasattr(event, 'fn') and event.levelno not in [bb.msg.BBLogFormatter.WARNONCE, bb.msg.BBLogFormatter.ERRORONCE]:
                     event.msg = event.fn + ': ' + event.msg
                 logging.getLogger(event.name).handle(event)
                 continue
@@ -875,11 +875,11 @@  def main(server, eventHandler, params, tf = TerminalFilter):
             for failure in taskfailures:
                 summary += "\n  %s" % failure
         if warnings:
-            summary += pluralise("\nSummary: There was %s WARNING message shown.",
-                                 "\nSummary: There were %s WARNING messages shown.", warnings)
+            summary += pluralise("\nSummary: There was %s WARNING message.",
+                                 "\nSummary: There were %s WARNING messages.", warnings)
         if return_value and errors:
-            summary += pluralise("\nSummary: There was %s ERROR message shown, returning a non-zero exit code.",
-                                 "\nSummary: There were %s ERROR messages shown, returning a non-zero exit code.", errors)
+            summary += pluralise("\nSummary: There was %s ERROR message, returning a non-zero exit code.",
+                                 "\nSummary: There were %s ERROR messages, returning a non-zero exit code.", errors)
         if summary and params.options.quiet == 0:
             print(summary)