Remove unnecessary FILE log level

Having a custom log level was unnecessarily complex and the routing of
debug messages to the stdout was not intuitive.
Using a Filter to decide whether a debug level message should be printed
to stdout based on the use of the --debug option is cleaner.

Author: bocekm

convert2rhel/logger.py

@@ -23,8 +23,6 @@
 INFO      (20)    Prints info message (no date/time, just plain message)
 TASK      (15)    CUSTOM LABEL - Prints a task header message (using asterisks)
 DEBUG     (10)    Prints debug message (using date/time)
-FILE      (5)     CUSTOM LABEL - Outputs with the DEBUG label but only to a file
-                  handle (using date/time)
 """
 import logging
 import os
@@ -81,52 +79,46 @@ class LogLevelTask(object):
     label = "TASK"
 
 
-class LogLevelFile(object):
-    level = 5
-    # Label messages DEBUG as it is contains the same messages as debug, just that they always go
-    # to the log file.
-    label = "DEBUG"
-
-
 def setup_logger_handler(log_name, log_dir):
     """Setup custom logging levels, handlers, and so on. Call this method
     from your application's main start point.
         log_name = the name for the log file
         log_dir = path to the dir where log file will be presented
     """
-    # set custom labels
+    # set the TASK custom label
     logging.addLevelName(LogLevelTask.level, LogLevelTask.label)
-    logging.addLevelName(LogLevelFile.level, LogLevelFile.label)
     logging.Logger.task = _task
-    logging.Logger.file = _file
-    logging.Logger.debug = _debug
     logging.Logger.critical = _critical
 
     # enable raising exceptions
     logging.raiseExceptions = True
-    # get root logger
+    # get the highest level app logger
     logger = logging.getLogger("convert2rhel")
-    # propagate
+    # propagate log messages to the root logger to be able to capture them in unit tests
+    # refence: https://github.com/oamg/convert2rhel/pull/179
     logger.propagate = True
-    # set default logging level
-    logger.setLevel(LogLevelFile.level)
+    # set the debug level as the default logging level
+    logger.setLevel(logging.DEBUG)
 
     # create sys.stdout handler for info/debug
     stdout_handler = logging.StreamHandler(sys.stdout)
     formatter = CustomFormatter("%(message)s")
     formatter.disable_colors(should_disable_color_output())
     stdout_handler.setFormatter(formatter)
+    debug_flag_filter = DebugFlagFilter()
+    stdout_handler.addFilter(debug_flag_filter)
+    # Set the debug level as the default level. Whether a debug message is printed is decided in DebugFlagFilter.
     stdout_handler.setLevel(logging.DEBUG)
     logger.addHandler(stdout_handler)
 
-    # create file handler
+    # create a log file handler
     if not os.path.isdir(log_dir):
         os.makedirs(log_dir)  # pragma: no cover
     handler = logging.FileHandler(os.path.join(log_dir, log_name), "a")
     formatter = CustomFormatter("%(message)s")
     formatter.disable_colors(True)
     handler.setFormatter(formatter)
-    handler.setLevel(LogLevelFile.level)
+    handler.setLevel(logging.DEBUG)
     logger.addHandler(handler)
 
 
@@ -143,6 +135,18 @@ def should_disable_color_output():
     return False
 
 
+class DebugFlagFilter(logging.Filter):
+    """Print debug messages to the stdout only when --debug is used."""
+
+    def filter(self, record):
+        from convert2rhel.toolopts import tool_opts
+
+        if record.levelno == logging.DEBUG and not tool_opts.debug:
+            # not logging a debug level message if the --debug option hasn't been used
+            return False
+        return True
+
+
 def archive_old_logger_files(log_name, log_dir):
     """Archive the old log files to not mess with multiple runs outputs.
     Every time a new run begins, this method will be called to archive the previous logs
@@ -187,27 +191,12 @@ def _task(self, msg, *args, **kwargs):
         self._log(LogLevelTask.level, msg, args, **kwargs)
 
 
-def _file(self, msg, *args, **kwargs):
-    if self.isEnabledFor(LogLevelFile.level):
-        self._log(LogLevelFile.level, msg, args, **kwargs)
-
-
 def _critical(self, msg, *args, **kwargs):
     if self.isEnabledFor(logging.CRITICAL):
         self._log(logging.CRITICAL, msg, args, **kwargs)
         sys.exit(msg)
 
 
-def _debug(self, msg, *args, **kwargs):
-    if self.isEnabledFor(logging.DEBUG):
-        from convert2rhel.toolopts import tool_opts
-
-        if tool_opts.debug:
-            self._log(logging.DEBUG, msg, args, **kwargs)
-        else:
-            self._log(LogLevelFile.level, msg, args, **kwargs)
-
-
 class bcolors:
     OKGREEN = "\033[92m"
     WARNING = "\033[93m"

convert2rhel/unit_tests/logger_test.py

@@ -79,7 +79,7 @@ def test_logger_custom_logger(tmpdir, caplog, clear_loggers):
     logger_module.setup_logger_handler(log_name=log_fname, log_dir=str(tmpdir))
     logger = logging.getLogger(__name__)
     logger.task("Some task: %s", "data")
-    logger.file("Some task write to file: %s", "data")
+    logger.debug("Some task write to file: %s", "data")
     with pytest.raises(SystemExit):
         logger.critical("Critical error: %s", "data")
 

convert2rhel/utils.py

@@ -367,12 +367,7 @@ def log_traceback(debug):
     on the debug parameter.
     """
     traceback_str = get_traceback_str()
-    if debug:
-        # Print the traceback to the user when debug option used
-        loggerinst.debug(traceback_str)
-    else:
-        # Print the traceback to the log file in any way
-        loggerinst.file(traceback_str)
+    loggerinst.debug(traceback_str)
 
 
 def get_traceback_str():