Blob Blame History Raw
From 9f9bfdfcb576846436f97275d6ee82004ceb4cb9 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Ale=C5=A1=20Mat=C4=9Bj?= <amatej@redhat.com>
Date: Thu, 4 Jun 2020 16:02:58 +0200
Subject: [PATCH 1/3] Add logfilelevel configuration (RhBug:1802074)

https://bugzilla.redhat.com/show_bug.cgi?id=1802074
---
 dnf.spec         |  2 +-
 dnf/logging.py   | 17 +++++++++++------
 doc/conf_ref.rst |  6 ++++++
 3 files changed, 18 insertions(+), 7 deletions(-)

diff --git a/dnf.spec b/dnf.spec
index 1423c6d5b5..27bae7aaa7 100644
--- a/dnf.spec
+++ b/dnf.spec
@@ -1,5 +1,5 @@
 # default dependencies
-%global hawkey_version 0.48.0
+%global hawkey_version 0.50.0
 %global libcomps_version 0.1.8
 %global libmodulemd_version 1.4.0
 %global rpm_version 4.14.0
diff --git a/dnf/logging.py b/dnf/logging.py
index bd660470a3..c578575e1c 100644
--- a/dnf/logging.py
+++ b/dnf/logging.py
@@ -70,11 +70,14 @@ def filter(self, record):
     4 : logging.DEBUG,
     5 : logging.DEBUG,
     6 : logging.DEBUG, # verbose value
+    7 : DDEBUG,
+    8 : SUBDEBUG,
+    9 : TRACE,
     }
 
 def _cfg_verbose_val2level(cfg_errval):
     assert 0 <= cfg_errval <= 10
-    return _VERBOSE_VAL_MAPPING.get(cfg_errval, DDEBUG)
+    return _VERBOSE_VAL_MAPPING.get(cfg_errval, TRACE)
 
 
 # Both the DNF default and the verbose default are WARNING. Note that ERROR has
@@ -157,13 +160,14 @@ def _presetup(self):
         self.stderr_handler = stderr
 
     @only_once
-    def _setup_file_loggers(self, verbose_level, logdir, log_size, log_rotate):
+    def _setup_file_loggers(self, logfile_level, verbose_level, logdir, log_size, log_rotate):
         logger_dnf = logging.getLogger("dnf")
         logger_dnf.setLevel(TRACE)
 
         # setup file logger
         logfile = os.path.join(logdir, dnf.const.LOG)
         handler = _create_filehandler(logfile, log_size, log_rotate)
+        handler.setLevel(logfile_level)
         logger_dnf.addHandler(handler)
         # put the marker in the file now:
         _paint_mark(logger_dnf)
@@ -185,14 +189,14 @@ def _setup_file_loggers(self, verbose_level, logdir, log_size, log_rotate):
         _paint_mark(logger_rpm)
 
     @only_once
-    def _setup(self, verbose_level, error_level, logdir, log_size, log_rotate):
+    def _setup(self, verbose_level, error_level, logfile_level, logdir, log_size, log_rotate):
         self._presetup()
 
         # temporarily turn off stdout/stderr handlers:
         self.stdout_handler.setLevel(SUPERCRITICAL)
         self.stderr_handler.setLevel(SUPERCRITICAL)
 
-        self._setup_file_loggers(verbose_level, logdir, log_size, log_rotate)
+        self._setup_file_loggers(logfile_level, verbose_level, logdir, log_size, log_rotate)
 
         logger_warnings = logging.getLogger("py.warnings")
         logger_warnings.addHandler(self.stderr_handler)
@@ -209,13 +213,14 @@ def _setup(self, verbose_level, error_level, logdir, log_size, log_rotate):
     def _setup_from_dnf_conf(self, conf, file_loggers_only=False):
         verbose_level_r = _cfg_verbose_val2level(conf.debuglevel)
         error_level_r = _cfg_err_val2level(conf.errorlevel)
+        logfile_level_r = _cfg_verbose_val2level(conf.logfilelevel)
         logdir = conf.logdir
         log_size = conf.log_size
         log_rotate = conf.log_rotate
         if file_loggers_only:
-            return self._setup_file_loggers(verbose_level_r, logdir, log_size, log_rotate)
+            return self._setup_file_loggers(logfile_level_r, verbose_level_r, logdir, log_size, log_rotate)
         else:
-            return self._setup(verbose_level_r, error_level_r, logdir, log_size, log_rotate)
+            return self._setup(verbose_level_r, error_level_r, logfile_level_r, logdir, log_size, log_rotate)
 
 
 class Timer(object):
diff --git a/doc/conf_ref.rst b/doc/conf_ref.rst
index cf442770c9..fed6efcec7 100644
--- a/doc/conf_ref.rst
+++ b/doc/conf_ref.rst
@@ -268,6 +268,12 @@ configuration file by your distribution to override the DNF defaults.
 
     Directory where the log files will be stored. Default is ``/var/log``.
 
+``logfilelevel``
+    :ref:`integer <integer-label>`
+
+    Log file messages output level, in the range 0 to 10. The higher the number the
+    more debug output is put to logs. Default is 9.
+
 .. _log_rotate-label:
 
 ``log_rotate``

From 1233d7da657ffbd03f9ffc274b648da0bb2898bf Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Ale=C5=A1=20Mat=C4=9Bj?= <amatej@redhat.com>
Date: Fri, 5 Jun 2020 09:21:15 +0200
Subject: [PATCH 2/3] Update unit logging test to reflect logfilelevel addition

---
 tests/test_logging.py | 16 +++++++++-------
 1 file changed, 9 insertions(+), 7 deletions(-)

diff --git a/tests/test_logging.py b/tests/test_logging.py
index a7fee3e67c..80e219d882 100644
--- a/tests/test_logging.py
+++ b/tests/test_logging.py
@@ -88,7 +88,7 @@ def test_setup(self):
         logger = logging.getLogger("dnf")
         with tests.support.patch_std_streams() as (stdout, stderr):
             self.logging._setup(
-                logging.INFO, logging.ERROR, self.logdir, self.log_size, self.log_rotate)
+                logging.INFO, logging.ERROR, dnf.logging.TRACE, self.logdir, self.log_size, self.log_rotate)
             self._bench(logger)
         self.assertEqual("i\n", stdout.getvalue())
         self.assertEqual("e\n", stderr.getvalue())
@@ -97,7 +97,7 @@ def test_setup_verbose(self):
         logger = logging.getLogger("dnf")
         with tests.support.patch_std_streams() as (stdout, stderr):
             self.logging._setup(
-                logging.DEBUG, logging.WARNING, self.logdir, self.log_size, self.log_rotate)
+                logging.DEBUG, logging.WARNING, dnf.logging.TRACE, self.logdir, self.log_size, self.log_rotate)
             self._bench(logger)
         self.assertEqual("d\ni\n", stdout.getvalue())
         self.assertEqual("w\ne\n", stderr.getvalue())
@@ -105,20 +105,22 @@ def test_setup_verbose(self):
     @mock.patch('dnf.logging.Logging._setup')
     def test_setup_from_dnf_conf(self, setup_m):
         conf = mock.Mock(
-            debuglevel=2, errorlevel=3, logdir=self.logdir,
+            debuglevel=2, errorlevel=3, logfilelevel=2, logdir=self.logdir,
             log_size=self.log_size, log_rotate=self.log_rotate)
         self.logging._setup_from_dnf_conf(conf)
         self.assertEqual(setup_m.call_args, mock.call(dnf.logging.INFO,
                                                       dnf.logging.WARNING,
+                                                      dnf.logging.INFO,
                                                       self.logdir,
                                                       self.log_size,
                                                       self.log_rotate))
         conf = mock.Mock(
-            debuglevel=6, errorlevel=6, logdir=self.logdir,
+            debuglevel=6, errorlevel=6, logfilelevel=6, logdir=self.logdir,
             log_size=self.log_size, log_rotate=self.log_rotate)
         self.logging._setup_from_dnf_conf(conf)
         self.assertEqual(setup_m.call_args, mock.call(dnf.logging.DEBUG,
                                                       dnf.logging.WARNING,
+                                                      dnf.logging.DEBUG,
                                                       self.logdir,
                                                       self.log_size,
                                                       self.log_rotate))
@@ -126,7 +128,7 @@ def test_setup_from_dnf_conf(self, setup_m):
     def test_file_logging(self):
         # log nothing to the console:
         self.logging._setup(
-            dnf.logging.SUPERCRITICAL, dnf.logging.SUPERCRITICAL,
+            dnf.logging.SUPERCRITICAL, dnf.logging.SUPERCRITICAL, dnf.logging.TRACE,
             self.logdir, self.log_size, self.log_rotate)
         logger = logging.getLogger("dnf")
         with tests.support.patch_std_streams() as (stdout, stderr):
@@ -145,7 +147,7 @@ def test_file_logging(self):
     def test_rpm_logging(self):
         # log everything to the console:
         self.logging._setup(
-            dnf.logging.SUBDEBUG, dnf.logging.SUBDEBUG,
+            dnf.logging.SUBDEBUG, dnf.logging.SUBDEBUG, dnf.logging.TRACE,
             self.logdir, self.log_size, self.log_rotate)
         logger = logging.getLogger("dnf.rpm")
         with tests.support.patch_std_streams() as (stdout, stderr):
@@ -167,7 +169,7 @@ def test_setup_only_once(self):
         logger = logging.getLogger("dnf")
         self.assertLength(logger.handlers, 0)
         self.logging._setup(
-            dnf.logging.SUBDEBUG, dnf.logging.SUBDEBUG,
+            dnf.logging.SUBDEBUG, dnf.logging.SUBDEBUG, dnf.logging.TRACE,
             self.logdir, self.log_size, self.log_rotate)
         cnt = len(logger.handlers)
         self.assertGreater(cnt, 0)

From 8a57da7229c67315d113b3c61cf981e1a7d81189 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Ale=C5=A1=20Mat=C4=9Bj?= <amatej@redhat.com>
Date: Thu, 25 Jun 2020 14:03:02 +0200
Subject: [PATCH 3/3] Control hawkey and librepo log verbosity with
 logfilelevel

= changelog =
msg: New config option 'logfilelevel' now controls logging to dnf.log, dnf.librepo.log and hawkey.log
type: enhancement
resolves: 1802074
---
 dnf/logging.py   | 11 +++++++----
 dnf/sack.py      |  2 +-
 doc/conf_ref.rst |  3 +++
 3 files changed, 11 insertions(+), 5 deletions(-)

diff --git a/dnf/logging.py b/dnf/logging.py
index c578575e1c..b5196988f7 100644
--- a/dnf/logging.py
+++ b/dnf/logging.py
@@ -43,6 +43,7 @@
 DDEBUG = 8  # used by anaconda (pyanaconda/payload/dnfpayload.py)
 SUBDEBUG = 6
 TRACE = 4
+ALL = 2
 
 def only_once(func):
     """Method decorator turning the method into noop on second or later calls."""
@@ -73,6 +74,7 @@ def filter(self, record):
     7 : DDEBUG,
     8 : SUBDEBUG,
     9 : TRACE,
+    10: ALL,   # more verbous librepo and hawkey
     }
 
 def _cfg_verbose_val2level(cfg_errval):
@@ -138,6 +140,7 @@ def __init__(self):
         logging.addLevelName(DDEBUG, "DDEBUG")
         logging.addLevelName(SUBDEBUG, "SUBDEBUG")
         logging.addLevelName(TRACE, "TRACE")
+        logging.addLevelName(ALL, "ALL")
         logging.captureWarnings(True)
         logging.raiseExceptions = False
 
@@ -160,7 +163,7 @@ def _presetup(self):
         self.stderr_handler = stderr
 
     @only_once
-    def _setup_file_loggers(self, logfile_level, verbose_level, logdir, log_size, log_rotate):
+    def _setup_file_loggers(self, logfile_level, logdir, log_size, log_rotate):
         logger_dnf = logging.getLogger("dnf")
         logger_dnf.setLevel(TRACE)
 
@@ -177,7 +180,7 @@ def _setup_file_loggers(self, logfile_level, verbose_level, logdir, log_size, lo
         logger_warnings.addHandler(handler)
 
         lr_logfile = os.path.join(logdir, dnf.const.LOG_LIBREPO)
-        libdnf.repo.LibrepoLog.addHandler(lr_logfile, verbose_level <= DEBUG)
+        libdnf.repo.LibrepoLog.addHandler(lr_logfile, logfile_level <= ALL)
 
         # setup RPM callbacks logger
         logger_rpm = logging.getLogger("dnf.rpm")
@@ -196,7 +199,7 @@ def _setup(self, verbose_level, error_level, logfile_level, logdir, log_size, lo
         self.stdout_handler.setLevel(SUPERCRITICAL)
         self.stderr_handler.setLevel(SUPERCRITICAL)
 
-        self._setup_file_loggers(logfile_level, verbose_level, logdir, log_size, log_rotate)
+        self._setup_file_loggers(logfile_level, logdir, log_size, log_rotate)
 
         logger_warnings = logging.getLogger("py.warnings")
         logger_warnings.addHandler(self.stderr_handler)
@@ -218,7 +221,7 @@ def _setup_from_dnf_conf(self, conf, file_loggers_only=False):
         log_size = conf.log_size
         log_rotate = conf.log_rotate
         if file_loggers_only:
-            return self._setup_file_loggers(logfile_level_r, verbose_level_r, logdir, log_size, log_rotate)
+            return self._setup_file_loggers(logfile_level_r, logdir, log_size, log_rotate)
         else:
             return self._setup(verbose_level_r, error_level_r, logfile_level_r, logdir, log_size, log_rotate)
 
diff --git a/dnf/sack.py b/dnf/sack.py
index fb8c70712f..3c6bc3bbe0 100644
--- a/dnf/sack.py
+++ b/dnf/sack.py
@@ -53,7 +53,7 @@ def _build_sack(base):
                 arch=base.conf.substitutions["arch"],
                 cachedir=cachedir, rootdir=base.conf.installroot,
                 logfile=os.path.join(base.conf.logdir, dnf.const.LOG_HAWKEY),
-                logdebug=base.conf.debuglevel > 2)
+                logdebug=base.conf.logfilelevel > 9)
 
 
 def _rpmdb_sack(base):
diff --git a/doc/conf_ref.rst b/doc/conf_ref.rst
index fed6efcec7..fdb44a657d 100644
--- a/doc/conf_ref.rst
+++ b/doc/conf_ref.rst
@@ -274,6 +274,9 @@ configuration file by your distribution to override the DNF defaults.
     Log file messages output level, in the range 0 to 10. The higher the number the
     more debug output is put to logs. Default is 9.
 
+    This option controls dnf.log, dnf.librepo.log and hawkey.log. Although dnf.librepo.log
+    and hawkey.log are affected only by setting the logfilelevel to 10.
+
 .. _log_rotate-label:
 
 ``log_rotate``