From 7e056e92b88d02c7b2009c6d8ce379cfb0328e69 Mon Sep 17 00:00:00 2001
From: Michal Bocek <mbocek@redhat.com>
Date: Tue, 10 Mar 2020 21:05:06 +0100
Subject: [PATCH] Unify logger.conf and the fallback code

- add missing 'leapp' logger to the logger.conf
  - it caused certain commands to get stuck on RHEL 7 when leapp package (with the
    conf file) was installed under certain circumstances, e.g. while running
    `snactor workflow sanity-check ipu` in our devel RHEL 7 vagrant with
    the leapp-repository NFS-synced
- use logging.Formatter.converter = time.gmtime for both the file config and fallback
  config to have the same (UTC) time, in both cases
- unify log levels
---
 etc/leapp/logger.conf    | 14 +++++++++----
 leapp/logger/__init__.py | 45 +++++++++++++++++++++++++++++++---------
 leapp/snactor/context.py |  2 +-
 3 files changed, 46 insertions(+), 15 deletions(-)

diff --git a/etc/leapp/logger.conf b/etc/leapp/logger.conf
index ee1cf919d..0e51226d1 100644
--- a/etc/leapp/logger.conf
+++ b/etc/leapp/logger.conf
@@ -1,5 +1,5 @@
 [loggers]
-keys=urllib3,root
+keys=urllib3,root,leapp
 
 [formatters]
 keys=leapp
@@ -18,16 +18,22 @@ qualname=urllib3
 handlers=stream
 
 [logger_root]
-level=DEBUG
-handlers=leapp_audit,stream
+level=ERROR
+handlers=stream
+
+[logger_leapp]
+level=NOTSET
+handlers=leapp_audit
+qualname=compiler.parser
 
 [handler_leapp_audit]
 class=leapp.logger.LeappAuditHandler
+level=NOTSET
 formatter=leapp
 args=()
 
 [handler_stream]
 class=StreamHandler
-level=ERROR
+level=NOTSET
 formatter=leapp
 args=(sys.stderr,)
diff --git a/leapp/logger/__init__.py b/leapp/logger/__init__.py
index b38f5035b..5d44810e2 100644
--- a/leapp/logger/__init__.py
+++ b/leapp/logger/__init__.py
@@ -52,26 +52,47 @@ def _remote_emit(self, log_data):
 
 
 def configure_logger(log_file=None):
+    """
+    Configure loggers as per the description below.
+
+    logger: root
+      level: ERROR
+      handler: StreamHandler
+        level: based on the debug/verbose options
+      logger: leapp
+        level: NOTSET
+        handler: LeappAuditHandler
+          level: NOTSET
+        handler: FileHandler
+          level: DEBUG
+      logger: urllib3
+        level: WARN
+
+    :return: The 'leapp' logger
+    """
     global _logger
     if not _logger:
         log_format = '%(asctime)s.%(msecs)-3d %(levelname)-8s PID: %(process)d %(name)s: %(message)s'
         log_date_format = '%Y-%m-%d %H:%M:%S'
         path = os.getenv('LEAPP_LOGGER_CONFIG', '/etc/leapp/logger.conf')
 
+        logging.Formatter.converter = time.gmtime
+
         if path and os.path.isfile(path):
             logging.config.fileConfig(path)
         else:  # Fall back logging configuration
-            logging.Formatter.converter = time.gmtime
             logging.basicConfig(
-                level=logging.ERROR,
+                level=logging.ERROR,  # The 'root' logger level
                 format=log_format,
                 datefmt=log_date_format,
-                stream=sys.stderr,
+                stream=sys.stderr  # The level of this StreamHandler is NOTSET at this moment
             )
             logging.getLogger('urllib3').setLevel(logging.WARN)
-            handler = LeappAuditHandler()
-            handler.setFormatter(logging.Formatter(fmt=log_format, datefmt=log_date_format))
-            logging.getLogger('leapp').addHandler(handler)
+
+            audit_handler = LeappAuditHandler()
+            audit_handler.setFormatter(logging.Formatter(fmt=log_format, datefmt=log_date_format))
+            # The level of both the 'leapp' logger and the audit handler is NOTSET, i.e. inherited from 'root'
+            logging.getLogger('leapp').addHandler(audit_handler)
 
         if log_file:
             file_handler = logging.FileHandler(os.path.join(get_config().get('logs', 'dir'), log_file))
@@ -79,10 +100,14 @@ def configure_logger(log_file=None):
             file_handler.setLevel(logging.DEBUG)
             logging.getLogger('leapp').addHandler(file_handler)
 
-        if is_verbose():
-            for handler in logging.getLogger().handlers:
-                if isinstance(handler, logging.StreamHandler):
-                    handler.setLevel(logging.DEBUG if is_debug() else logging.INFO)
+        for handler in logging.getLogger().handlers:
+            if isinstance(handler, logging.StreamHandler):
+                if is_debug():
+                    handler.setLevel(logging.DEBUG)
+                elif is_verbose():
+                    handler.setLevel(logging.INFO)
+                else:
+                    handler.setLevel(logging.ERROR)
 
         _logger = logging.getLogger('leapp')
         _logger.info('Logging has been initialized')
diff --git a/leapp/snactor/context.py b/leapp/snactor/context.py
index d3ab66502..b3673b045 100644
--- a/leapp/snactor/context.py
+++ b/leapp/snactor/context.py
@@ -10,7 +10,7 @@ def last_snactor_context(connection=None):
     Retrieves the last snactor-run context from the database. It generates a new one if none has been found.
 
     :param connection: Database connection to use instead of the default connection.
-    :returns: String representing the latest snactor-run context uuid.
+    :return: String representing the latest snactor-run context uuid.
     """
     with get_connection(db=connection) as db:
         cursor = db.execute('''