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``