1855158 – Packages installed / removed via DNF Python api are not logged to /var/log/dnf.log

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1855158 - Packages installed / removed via DNF Python api are not logged to /var/log/dnf.log

Summary: Packages installed / removed via DNF Python api are not logged to /var/log/dn...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 8
Classification:	Red Hat
Component:	dnf
Sub Component:
Version:	8.2
Hardware:	x86_64
OS:	Linux
Priority:	medium
Severity:	medium
Target Milestone:	rc
Target Release:	8.0
Assignee:	Marek Blaha
QA Contact:	Jan Blazek
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2020-07-09 06:20 UTC by Ishwar Kanse
Modified:	2024-10-01 16:41 UTC (History)
CC List:	5 users (show)
Fixed In Version:	dnf-4.4.2-3.el8
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2021-05-18 15:00:36 UTC
Type:	Bug
Target Upstream Version:
Embargoed:
Dependent Products:
Flags:	pm-rhel: mirror+

Attachments	(Terms of Use)

Description Ishwar Kanse 2020-07-09 06:20:36 UTC

Description of problem:

When installing a package via the DNF Python API, the changes to the installed / removed packages are not logged to /var/log/dnf.log


Version-Release number of selected component (if applicable):

~~~
rpm -qa | grep -i dnf
dnf-plugin-subscription-manager-1.26.17-1.el8_2.x86_64
python3-dnf-plugin-spacewalk-2.8.5-11.module+el8.1.0+3455+3ddf2832.noarch
dnf-data-4.2.17-6.el8.noarch
dnf-4.2.17-6.el8.noarch
dnf-plugins-core-4.0.12-3.el8.noarch
dnf-plugin-spacewalk-2.8.5-11.module+el8.1.0+3455+3ddf2832.noarch
python3-dnf-4.2.17-6.el8.noarch
python3-dnf-plugins-core-4.0.12-3.el8.noarch
libdnf-0.39.1-5.el8.x86_64
python3-libdnf-0.39.1-5.el8.x86_64
~~~

How reproducible:

Always

Steps to Reproduce:

~~~
import dnf
base = dnf.Base()
base.conf.read()
base.setup_loggers()
base.read_all_repos()
base.fill_sack()
base.install("nano")
base.resolve()
base.download_packages(base.transaction.install_set)
base.do_transaction()
~~~

python3 testdnfapi.py

Actual results:

~~~
2020-07-09T06:09:18Z INFO --- logging initialized ---
2020-07-09T06:09:18Z DEBUG User-Agent: constructed: 'libdnf (Red Hat Enterprise Linux 8.2; generic; Linux.x86_64)'
2020-07-09T06:09:18Z DEBUG repo: using cache for: docker-ce-stable
2020-07-09T06:09:18Z DEBUG docker-ce-stable: using metadata from Mon 22 Jun 2020 10:31:42 PM UTC.
2020-07-09T06:09:18Z DEBUG repo: using cache for: google-cloud-sdk
2020-07-09T06:09:18Z DEBUG google-cloud-sdk: using metadata from Tue 16 Feb 1999 02:53:56 PM UTC.
2020-07-09T06:09:18Z DEBUG repo: using cache for: ansible-2.9-for-rhel-8-x86_64-rpms
2020-07-09T06:09:18Z DEBUG ansible-2.9-for-rhel-8-x86_64-rpms: using metadata from Mon 22 Jun 2020 01:43:04 PM UTC.
2020-07-09T06:09:18Z DEBUG repo: using cache for: rhel-8-for-x86_64-appstream-rpms
2020-07-09T06:09:18Z DEBUG rhel-8-for-x86_64-appstream-rpms: using metadata from Wed 08 Jul 2020 04:08:35 PM UTC.
2020-07-09T06:09:18Z DEBUG repo: using cache for: rhel-8-for-x86_64-baseos-rpms
2020-07-09T06:09:18Z DEBUG rhel-8-for-x86_64-baseos-rpms: using metadata from Mon 06 Jul 2020 04:17:07 AM UTC.
2020-07-09T06:09:18Z INFO Last metadata expiration check: 1:58:05 ago on Thu 09 Jul 2020 04:11:13 AM UTC.
2020-07-09T06:09:19Z DDEBUG timer: sack setup: 982 ms
2020-07-09T06:09:20Z DDEBUG timer: depsolve: 620 ms
2020-07-09T06:09:24Z INFO Running transaction check
2020-07-09T06:09:24Z INFO Transaction check succeeded.
2020-07-09T06:09:24Z INFO Running transaction test
2020-07-09T06:09:24Z INFO Transaction test succeeded.
2020-07-09T06:09:24Z DDEBUG timer: transaction test: 127 ms
2020-07-09T06:09:24Z INFO Running transaction
2020-07-09T06:09:24Z DDEBUG RPM transaction start.
2020-07-09T06:09:24Z DDEBUG RPM transaction over.
2020-07-09T06:09:25Z DDEBUG timer: verify transaction: 167 ms
2020-07-09T06:09:25Z DDEBUG timer: transaction: 580 ms

~~~


Expected results:

~~~
2020-07-09T06:07:50Z INFO --- logging initialized ---
2020-07-09T06:07:50Z DDEBUG timer: config: 2 ms
2020-07-09T06:07:50Z DEBUG Loaded plugins: AmazonID, builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, needs-restarting, playground, product-id, repoclosure, repodiff, repograph, repomanage, reposync, subscription-manager, uploadprofile
2020-07-09T06:07:50Z INFO Updating Subscription Management repositories.
2020-07-09T06:07:53Z DEBUG YUM version: 4.2.17
2020-07-09T06:07:53Z DDEBUG Command: yum install nano 
2020-07-09T06:07:53Z DDEBUG Installroot: /
2020-07-09T06:07:53Z DDEBUG Releasever: 8
2020-07-09T06:07:53Z DEBUG cachedir: /var/cache/dnf
2020-07-09T06:07:53Z DDEBUG Base command: install
2020-07-09T06:07:53Z DDEBUG Extra commands: ['install', 'nano']
2020-07-09T06:07:53Z DEBUG User-Agent: constructed: 'libdnf (Red Hat Enterprise Linux 8.2; generic; Linux.x86_64)'
2020-07-09T06:07:53Z DEBUG repo: using cache for: docker-ce-stable
2020-07-09T06:07:53Z DEBUG docker-ce-stable: using metadata from Mon 22 Jun 2020 10:31:42 PM UTC.
2020-07-09T06:07:53Z DEBUG repo: using cache for: google-cloud-sdk
2020-07-09T06:07:53Z DEBUG google-cloud-sdk: using metadata from Tue 16 Feb 1999 02:53:56 PM UTC.
2020-07-09T06:07:53Z DEBUG repo: using cache for: ansible-2.9-for-rhel-8-x86_64-rpms
2020-07-09T06:07:53Z DEBUG ansible-2.9-for-rhel-8-x86_64-rpms: using metadata from Mon 22 Jun 2020 01:43:04 PM UTC.
2020-07-09T06:07:53Z DEBUG repo: using cache for: rhel-8-for-x86_64-appstream-rpms
2020-07-09T06:07:53Z DEBUG rhel-8-for-x86_64-appstream-rpms: using metadata from Wed 08 Jul 2020 04:08:35 PM UTC.
2020-07-09T06:07:53Z DEBUG repo: using cache for: rhel-8-for-x86_64-baseos-rpms
2020-07-09T06:07:53Z DEBUG rhel-8-for-x86_64-baseos-rpms: using metadata from Mon 06 Jul 2020 04:17:07 AM UTC.
2020-07-09T06:07:53Z INFO Last metadata expiration check: 1:56:40 ago on Thu 09 Jul 2020 04:11:13 AM UTC.
2020-07-09T06:07:54Z DDEBUG timer: sack setup: 1063 ms
2020-07-09T06:07:54Z DEBUG Completion plugin: Generating completion cache...
2020-07-09T06:07:54Z DEBUG --> Starting dependency resolution
2020-07-09T06:07:55Z DEBUG ---> Package nano.x86_64 2.9.8-1.el8 will be installed
2020-07-09T06:07:55Z DEBUG --> Finished dependency resolution
2020-07-09T06:07:55Z DDEBUG timer: depsolve: 617 ms
2020-07-09T06:07:55Z INFO Dependencies resolved.
2020-07-09T06:07:55Z INFO ========================================================================================================
 Package        Architecture     Version                  Repository                               Size
========================================================================================================
Installing:
 nano           x86_64           2.9.8-1.el8              rhel-8-for-x86_64-baseos-rpms           580 k

Transaction Summary
========================================================================================================
Install  1 Package

2020-07-09T06:07:55Z INFO Total size: 580 k
2020-07-09T06:07:55Z INFO Installed size: 2.2 M
2020-07-09T06:07:56Z INFO Downloading Packages:
2020-07-09T06:07:56Z INFO Running transaction check
2020-07-09T06:07:56Z INFO Transaction check succeeded.
2020-07-09T06:07:56Z INFO Running transaction test
2020-07-09T06:07:56Z INFO Transaction test succeeded.
2020-07-09T06:07:56Z DDEBUG timer: transaction test: 128 ms
2020-07-09T06:07:56Z INFO Running transaction
2020-07-09T06:07:56Z DDEBUG RPM transaction start.
2020-07-09T06:07:57Z DDEBUG RPM transaction over.
2020-07-09T06:07:57Z DDEBUG timer: verify transaction: 169 ms
2020-07-09T06:07:57Z DDEBUG timer: transaction: 594 ms
2020-07-09T06:07:57Z DEBUG Completion plugin: Generating completion cache...
2020-07-09T06:07:57Z INFO Installed products updated.
2020-07-09T06:07:58Z INFO 
Installed:
  nano-2.9.8-1.el8.x86_64                                                                               

2020-07-09T06:07:58Z INFO Complete!
2020-07-09T06:07:58Z DDEBUG Cleaning up.
2020-07-09T06:07:58Z DDEBUG /var/cache/dnf/rhel-8-for-x86_64-baseos-rpms-51b3b78d5698246b/packages/nano-2.9.8-1.el8.x86_64.rpm removed

~~~


Additional info:

This expected results from above is from package install via yum

Comment 1 Marek Blaha 2020-07-14 13:15:02 UTC

The transaction table (and other lines from dnf.log) are printed by CLI layer of the DNF and the code is not executed at all when DNF is used via API.
Is it viable for your use-case to read /var/log/dnf.rpm.log file instead? This file contains information about installed/removed/upgraded packages and rpm messages.

Comment 2 Marek Blaha 2020-07-22 07:53:01 UTC

I would like to close this as "not a bug" from dnf point of view. Please is it all right for you to use /var/log/dnf.rpm.log file instead of /var/log/dnf.log for checking which packages were installed/removed?

Comment 3 Ishwar Kanse 2020-07-22 08:09:50 UTC

Hi Marek,

I've a case opened by a customer asking for this request. The customer has replied that he will let me know if it works for him to use dnf.rpm.log instead. I'll get an update on that case. Can we keep this open for a couple of days while I get a reply from him ?

Thanks,
Ishwar

Comment 4 Marek Blaha 2020-07-22 08:29:29 UTC

Of course, thanks for the update.

Comment 5 Ishwar Kanse 2020-07-28 00:36:32 UTC

Hi, The customer came back on this one and they want the dnf.log to be updated too.

'Conclusion for the dnf logging - our auditors requires dnf.log to be updated as well.'

Comment 30 errata-xmlrpc 2021-05-18 15:00:36 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (dnf bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2021:1657

Note You need to log in before you can comment on or make changes to this bug.