Job logging: introduce buffered behavior

This introduces an option that adds the buffering layer on top of
the file logging handler.

Plamen Dimitrov has reported issues with heavy logging causing the
status server/client connection to reset.  He has suggested and has
been using a workaround like this.

Reference: avocado-framework#5881
Signed-off-by: Cleber Rosa <[email protected]>

avocado/core/job.py

@@ -89,6 +89,19 @@ def register_job_options():
         key_type=list,
     )
 
+    help_msg = (
+        "Whether to add a layer of memory based buffering with a given number of "
+        "entries.  If set to 0 or less than 0, buffering disabled."
+    )
+    settings.register_option(
+        section="job.run",
+        key="logging_buffer_size",
+        help_msg=help_msg,
+        default=0,
+        metavar="SIZE",
+        key_type=int,
+    )
+
 
 register_job_options()
 
@@ -210,29 +223,33 @@ def __start_job_logging(self):
         # Enable test logger
         full_log = os.path.join(self.logdir, "full.log")
         fmt = "%(asctime)s %(name)s %(module)-16.16s L%(lineno)-.4d %(levelname)-5.5s| %(message)s"
+        buffer_size = self.config.get("job.run.logging_buffer_size")
         output.add_log_handler(
             LOG_JOB,
             logging.FileHandler,
             self.logfile,
             self.loglevel,
             fmt,
-            handler_filter=output.FilterTestMessage(),
+            output.FilterTestMessage(),
+            buffer_size,
         )
         output.add_log_handler(
             logging.getLogger(""),
             logging.FileHandler,
             full_log,
             self.loglevel,
             fmt,
-            handler_filter=output.FilterTestMessage(),
+            output.FilterTestMessage(),
+            buffer_size,
         )
         output.add_log_handler(
             logging.getLogger(""),
             logging.FileHandler,
             full_log,
             self.loglevel,
             "",
-            handler_filter=output.FilterTestMessageOnly(),
+            output.FilterTestMessageOnly(),
+            buffer_size,
         )
 
         # --store-logging-stream files
@@ -251,15 +268,17 @@ def __start_job_logging(self):
                 logfile,
                 level,
                 fmt,
-                handler_filter=output.FilterTestMessage(),
+                output.FilterTestMessage(),
+                buffer_size,
             )
             output.add_log_handler(
                 enabled_logger,
                 logging.FileHandler,
                 logfile,
                 level,
                 "",
-                handler_filter=output.FilterTestMessageOnly(),
+                output.FilterTestMessageOnly(),
+                buffer_size,
             )
 
     def __stop_job_logging(self):

avocado/core/output.py

@@ -17,6 +17,7 @@
 """
 import errno
 import logging
+import logging.handlers
 import os
 import re
 import sys
@@ -666,6 +667,7 @@ def add_log_handler(
     level=logging.DEBUG,
     fmt="%(name)s: %(message)s",
     handler_filter=None,
+    buffer_size=0,
 ):
     """
     Add handler to a logger.
@@ -678,6 +680,9 @@ def add_log_handler(
     :param level: Log level (defaults to `INFO``)
     :param fmt: Logging format (defaults to ``%(name)s: %(message)s``)
     :param handler_filter: Logging filter class based on logging.Filter
+    :param buffer_size: whether to add a layer of memory based buffering with
+                        a given number of entries.  If <= 0, buffering is
+                        disabled.
     """
 
     def save_handler(logger_name, handler):
@@ -700,6 +705,11 @@ def save_handler(logger_name, handler):
     if handler_filter:
         handler.addFilter(handler_filter)
 
+    if klass == logging.FileHandler and buffer_size > 0:
+        buffered_wrapper = logging.handlers.MemoryHandler(buffer_size)
+        buffered_wrapper.setTarget(handler)
+        handler = buffered_wrapper
+
     logger.addHandler(handler)
     save_handler(logger.name, handler)
     return handler