Bug 1580022

Summary: /var/log/dnf.librepo.log way too verbose and big
Product: [Fedora] Fedora Reporter: Harald Reindl <h.reindl>
Component: dnfAssignee: Lukáš Hrázký <lhrazky>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: medium    
Version: rawhideCC: dmach, fdc, lhrazky, mblaha, packaging-team-maint, rpm-software-management, vmukhame
Target Milestone: ---Keywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: dnf-4.2.7-2.fc30 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-07-30 01:14:48 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Harald Reindl 2018-05-19 07:46:37 UTC
can /var/log/dnf.librepo.log be silenced somehow?

this is completly useless debug information and i have virtual servers which are below 700 MB at a whole while after a dist-upgrade with dnf this logfile was way above 100 MB on each and every VM

there is no reason to log that verbose until dnf was called with a -v flag and the same for /var/log/hawkey.log

[root@testserver:~]$ > /var/log/dnf.librepo.log
[root@testserver:~]$ dnf clean metadata && dnf upgrade
[root@testserver:~]$ ls /var/log/dnf.librepo.log
-rw------- 1 root root 384K 2018-05-19 09:42 /var/log/dnf.librepo.log

hopefully that stays a symlink to /dev/null now
lrwxrwxrwx 1 root root 9 2018-05-19 09:41 /var/log/dnf.librepo.log -> /dev/null

09:42:49 select_next_target: Selecting mirror for: Packages/c/ca-certificates-2018.2.24-1.0.fc27.noarch.rpm
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://mirror.karneval.cz/fedora/linux/updates/testing/27/x86_64/
09:42:49 prepare_next_transfer: URL: http://mirror.karneval.cz/pub/linux/fedora/linux/updates/testing/27/x86_64/Packages/c/ca-certificates-2018.2.24-1.0.fc27.noarch.rpm
09:42:49 prepare_next_transfer: Resume ignored, existing file was not originally being downloaded by Librepo
09:42:49 select_next_target: Selecting mirror for: Packages/c/cmake-3.11.2-1.fc27.x86_64.rpm
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://mirror.karneval.cz/fedora/linux/updates/testing/27/x86_64/
09:42:49 prepare_next_transfer: URL: http://mirror.karneval.cz/pub/linux/fedora/linux/updates/testing/27/x86_64/Packages/c/cmake-3.11.2-1.fc27.x86_64.rpm
09:42:49 prepare_next_transfer: Resume ignored, existing file was not originally being downloaded by Librepo
09:42:49 select_next_target: Selecting mirror for: Packages/c/cmake-data-3.11.2-1.fc27.noarch.rpm
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://mirror.karneval.cz/fedora/linux/updates/testing/27/x86_64/
09:42:49 prepare_next_transfer: URL: http://mirror.karneval.cz/pub/linux/fedora/linux/updates/testing/27/x86_64/Packages/c/cmake-data-3.11.2-1.fc27.noarch.rpm
09:42:49 prepare_next_transfer: Resume ignored, existing file was not originally being downloaded by Librepo
09:42:49 select_next_target: Selecting mirror for: Packages/c/cmake-filesystem-3.11.2-1.fc27.x86_64.rpm
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://mirror.karneval.cz/fedora/linux/updates/testing/27/x86_64/
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://fedora.inode.at/fedora/updates/testing/27/x86_64/
09:42:49 prepare_next_transfer: URL: http://fedora.inode.at/updates/testing/27/x86_64/Packages/c/cmake-filesystem-3.11.2-1.fc27.x86_64.rpm
09:42:49 prepare_next_transfer: Resume ignored, existing file was not originally being downloaded by Librepo
09:42:49 select_next_target: Selecting mirror for: Packages/c/cmake-rpm-macros-3.11.2-1.fc27.noarch.rpm
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://mirror.karneval.cz/fedora/linux/updates/testing/27/x86_64/
09:42:49 select_suitable_mirror: Skipping rsync url: rsync://fedora.inode.at/fedora/updates/testing/27/x86_64/
09:42:49 prepare_next_transfer: URL: http://fedora.inode.at/updates/testing/27/x86_64/Packages/c/cmake-rpm-macros-3.11.2-1.fc27.noarch.rpm
09:42:49 prepare_next_transfer: Resume ignored, existing file was not originally being downloaded by Librepo
09:42:49 lr_download: Downloading started

Aktualisiert:
  ca-certificates.noarch 2018.2.24-1.0.fc27 cmake.x86_64 3.11.2-1.fc27                cmake-data.noarch 3.11.2-1.fc27       cmake-filesystem.x86_64 3.11.2-1.fc27
  cmake-rpm-macros.noarch 3.11.2-1.fc27     curl.x86_64 7.55.1-11.fc27                glibc.x86_64 2.26-28.fc27             glibc-common.x86_64 2.26-28.fc27
  glibc-devel.x86_64 2.26-28.fc27           glibc-headers.x86_64 2.26-28.fc27         glibc-langpack-de.x86_64 2.26-28.fc27 glibc-langpack-en.x86_64 2.26-28.fc27
  graphviz.x86_64 2.40.1-11.fc27            libcrypt-nss.x86_64 2.26-28.fc27          libcurl.x86_64 7.55.1-11.fc27         libcurl-devel.x86_64 7.55.1-11.fc27
  perl-Errno.x86_64 1.28-405.fc27           perl-IO.x86_64 1.38-405.fc27              perl-IO-Zlib.noarch 1:1.10-405.fc27   perl-Locale-Maketext-Simple.noarch 1:0.21-405.fc27
  perl-Math-Complex.noarch 1.59-405.fc27    perl-Memoize.noarch 1.03-405.fc27         perl-Pod-Html.noarch 1.22.02-405.fc27 perl-Test.noarch 1.30-405.fc27
  perl-devel.x86_64 4:5.26.2-405.fc27       perl-interpreter.x86_64 4:5.26.2-405.fc27 perl-libs.x86_64 4:5.26.2-405.fc27    perl-macros.x86_64 4:5.26.2-405.fc27
  python3-sssdconfig.noarch 1.16.1-8.fc27

Comment 1 Harald Reindl 2018-05-19 07:52:27 UTC
the same for /var/log/dnf.log - WTF

2018-05-19T07:43:25Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7c18>, 0, None), {}
2018-05-19T07:43:25Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7d30>, 0, None), {}
2018-05-19T07:43:26Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7f28>, 0, None), {}
2018-05-19T07:43:26Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7dd8>, 0, None), {}
2018-05-19T07:43:26Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7f98>, 0, None), {}
2018-05-19T07:43:26Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49beaecf8>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7da0>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7e10>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7f60>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c6128>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c6080>, 0, None), {}
2018-05-19T07:43:27Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c60b8>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c6048>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c6160>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b79b0>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc4ab1cee48>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c6198>, 0, None), {}
2018-05-19T07:43:28Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2c61d0>, 0, None), {}
2018-05-19T07:43:29Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7ac8>, 0, None), {}
2018-05-19T07:43:30Z SUBDEBUG Call: RPMPayload._end_cb: (<dnf.repo.RPMPayload object at 0x7fc49b2b7fd0>, 0, None), {}

2018-05-18T12:56:32Z SUBDEBUG
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 64, in main
    return _main(base, args, cli_class, option_parser_class)
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 99, in _main
    return cli_run(cli, base)
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 115, in cli_run
    cli.run()
  File "/usr/lib/python3.6/site-packages/dnf/cli/cli.py", line 1014, in run
    return self.command.run()
  File "/usr/lib/python3.6/site-packages/dnf-plugins/repomanage.py", line 65, in run
    raise dnf.exceptions.Error(_("No files to process"))
dnf.exceptions.Error: Keine zu verarbeitenden Dateien
2018-05-18T12:56:32Z CRITICAL Fehler: Keine zu verarbeitenden Dateien
2018-05-18T12:56:33Z INFO --- logging initialized ---
2018-05-18T12:56:33Z DDEBUG timer: config: 5 ms
2018-05-18T12:56:33Z DEBUG Loaded plugins: builddep, config-manager, copr, debug, debuginfo-install, download, etckeeper, generate_completion_cache, leaves, needs-restarting, playground, repoclosure, repograph, repomanage, reposync, show-leaves
2018-05-18T12:56:33Z DEBUG DNF version: 2.7.5
2018-05-18T12:56:33Z DDEBUG Command: dnf repomanage --old /repo/fc27/native/
2018-05-18T12:56:33Z DDEBUG Installroot: /
2018-05-18T12:56:33Z DDEBUG Releasever: 27
2018-05-18T12:56:33Z DEBUG cachedir: /var/cache/dnf
2018-05-18T12:56:33Z DDEBUG Base command: repomanage
2018-05-18T12:56:33Z DDEBUG Extra commands: ['repomanage', '--old', '/repo/fc27/native/']
2018-05-18T12:56:33Z DDEBUG timer: sack setup: 211 ms
2018-05-18T12:56:33Z DDEBUG Cleaning up.
2018-05-18T12:56:33Z SUBDEBUG
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 64, in main
    return _main(base, args, cli_class, option_parser_class)
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 99, in _main
    return cli_run(cli, base)
  File "/usr/lib/python3.6/site-packages/dnf/cli/main.py", line 115, in cli_run
    cli.run()
  File "/usr/lib/python3.6/site-packages/dnf/cli/cli.py", line 1014, in run
    return self.command.run()
  File "/usr/lib/python3.6/site-packages/dnf-plugins/repomanage.py", line 65, in run
    raise dnf.exceptions.Error(_("No files to process"))
dnf.exceptions.Error: Keine zu verarbeitenden Dateien
2018-05-18T12:56:33Z CRITICAL Fehler: Keine zu verarbeitenden Dateien
2018-05-18T12:56:33Z INFO --- logging initialized ---
2018-05-18T12:56:33Z DDEBUG timer: config: 5 ms
2018-05-18T12:56:33Z DEBUG Loaded plugins: builddep, config-manager, copr, debug, debuginfo-install, download, etckeeper, generate_completion_cache, leaves, needs-restarting, playground, repoclosure, repograph, repomanage, reposync, show-leaves
2018-05-18T12:56:33Z DEBUG DNF version: 2.7.5
2018-05-18T12:56:33Z DDEBUG Command: dnf repomanage --old /repo/SRPMS/
2018-05-18T12:56:33Z DDEBUG Installroot: /
2018-05-18T12:56:33Z DDEBUG Releasever: 27
2018-05-18T12:56:33Z DEBUG cachedir: /var/cache/dnf
2018-05-18T12:56:33Z DDEBUG Base command: repomanage
2018-05-18T12:56:33Z DDEBUG Extra commands: ['repomanage', '--old', '/repo/SRPMS/']
2018-05-18T12:56:33Z DDEBUG timer: sack setup: 215 ms
2018-05-18T12:56:38Z DDEBUG Cleaning up.

Comment 2 Ben Cotton 2018-11-27 14:17:40 UTC
This message is a reminder that Fedora 27 is nearing its end of life.
On 2018-Nov-30  Fedora will stop maintaining and issuing updates for
Fedora 27. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora  'version' of '27'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 27 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 3 Alan Pevec 2019-03-19 20:29:23 UTC
on RHEL 8 Beta I ended up with > 7 GB DEBUG level lines in dnf.librepo.log:
-rw-r--r--. 1 root   root   7376408576 Mar 19 16:20 dnf.librepo.log

Comment 4 Alan Pevec 2019-03-19 20:39:13 UTC
ok, there is already RHEL 8 bug 1678598

Comment 5 Lukáš Hrázký 2019-04-18 14:15:23 UTC
Pull requests:
https://github.com/rpm-software-management/libdnf/pull/707
https://github.com/rpm-software-management/dnf/pull/1363

A relevant Fedora bug with more discussion: https://bugzilla.redhat.com/show_bug.cgi?id=1355764
(this could probably be closed as a duplicate of that one)

Comment 6 Ben Cotton 2019-05-02 19:21:08 UTC
This message is a reminder that Fedora 28 is nearing its end of life.
On 2019-May-28 Fedora will stop maintaining and issuing updates for
Fedora 28. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora 'version' of '28'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 28 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 7 Ben Cotton 2019-05-02 19:38:45 UTC
This message is a reminder that Fedora 28 is nearing its end of life.
On 2019-May-28 Fedora will stop maintaining and issuing updates for
Fedora 28. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora 'version' of '28'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 28 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 8 Fedora Update System 2019-07-04 13:50:26 UTC
FEDORA-2019-58c2d3f1aa has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-58c2d3f1aa

Comment 9 Fedora Update System 2019-07-05 00:45:58 UTC
dnf-4.2.7-1.fc30, libdnf-0.35.1-1.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-58c2d3f1aa

Comment 10 Fedora Update System 2019-07-23 07:21:22 UTC
FEDORA-2019-672a74d688 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-672a74d688

Comment 11 Fedora Update System 2019-07-24 01:44:17 UTC
dnf-4.2.7-2.fc30, libdnf-0.35.1-2.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-672a74d688

Comment 12 Fedora Update System 2019-07-30 01:14:48 UTC
dnf-4.2.7-2.fc30, libdnf-0.35.1-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.