From 9f9bfdfcb576846436f97275d6ee82004ceb4cb9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ale=C5=A1=20Mat=C4=9Bj?= 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 ` + + 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?= 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?= 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``