Bug 1627534

Summary: A lot of errors "TransactionItem not found" during update
Product: [Fedora] Fedora Reporter: Mikhail <mikhail.v.gavrilov>
Component: dnfAssignee: rpm-software-management
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: rawhideCC: awilliam, dmach, fweimer, mblaha, mhatina, packaging-team-maint, rpm-software-management, vmukhame, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-09-12 16:30:31 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:
Embargoed:
Attachments:
Description Flags
downgrade in chroot log none

Description Mikhail 2018-09-10 19:57:49 UTC
Created attachment 1482227 [details]
downgrade in chroot log

Description of problem:


Version-Release number of selected component (if applicable):
# dnf --version
3.2.0
  Installed: dnf-0:3.2.0-2.fc29.noarch at Fri 10 Aug 2018 11:42:27 AM GMT
  Built    : Fedora Project at Wed 08 Aug 2018 04:52:11 PM GMT

  Installed: rpm-0:4.14.2-1.fc30.x86_64 at Fri 24 Aug 2018 03:02:15 AM GMT
  Built    : Fedora Project at Tue 21 Aug 2018 11:33:49 AM GMT


How reproducible:


Steps to Reproduce:
1. Boot from LiveUSB
2. Look how recognized partitions.
# fdisk -l
3. Create mount point
# mkdir /mnt/point
4. Mount root и EFI partitions
# mount /dev/nvme0n1p2 /mnt/point/
# mount /dev/nvme0n1p1 /mnt/point/boot/efi
5. Mount /proc
# mount --bind /proc /mnt/point/proc
6. Enter in chroot
# chroot /mnt/point/
7. Look dnf history
# dnf history
8. Try undone last update
# dnf history undo 102 --refresh

Actual results:
A lot of error messages:
Running transaction
  Preparing        :                                                                                                                                                                  1/1 
  Running scriptlet: grub2-common-1:2.02-51.fc30.noarch                                                                                                                               1/1 
  Downgrading      : grub2-common-1:2.02-51.fc30.noarch                                                                                                                              1/22 
  Downgrading      : grub2-tools-minimal-1:2.02-51.fc30.x86_64                                                                                                                       2/22 
  Downgrading      : grub2-tools-extra-1:2.02-51.fc30.x86_64                                                                                                                         3/22 
  Running scriptlet: grub2-tools-1:2.02-51.fc30.x86_64                                                                                                                               4/22 
  Downgrading      : grub2-tools-1:2.02-51.fc30.x86_64                                                                                                                               4/22 
  Running scriptlet: grub2-tools-1:2.02-51.fc30.x86_64                                                                                                                               4/22 
  Downgrading      : grub2-pc-modules-1:2.02-51.fc30.noarch                                                                                                                          5/22 
  Downgrading      : grub2-pc-1:2.02-51.fc30.x86_64                                                                                                                                  6/22 
  Downgrading      : grub2-efi-ia32-1:2.02-51.fc30.x86_64                                                                                                                            7/22 
  Downgrading      : grub2-efi-x64-1:2.02-51.fc30.x86_64                                                                                                                             8/22 
  Downgrading      : grub2-efi-ia32-cdboot-1:2.02-51.fc30.x86_64                                                                                                                     9/22 
  Downgrading      : grub2-efi-x64-cdboot-1:2.02-51.fc30.x86_64                                                                                                                     10/22 
  Downgrading      : grub2-tools-efi-1:2.02-51.fc30.x86_64                                                                                                                          11/22 
Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 253, in callback
    self._elemProgress(key, amount)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 296, in _elemProgress
    _, _, tsi = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: grub2-pc

Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 265, in callback
    self._uninst_progress(amount, total, key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 347, in _uninst_progress
    _, _, tsi = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: grub2-pc

Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 265, in callback
    self._uninst_progress(amount, total, key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 347, in _uninst_progress
    _, _, tsi = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: grub2-pc


but undone operation was successful.

Expected results:
No error messages.

Additional info:

Comment 1 Zbigniew Jędrzejewski-Szmek 2018-09-11 13:47:46 UTC
I'm seeing the same error, on a normal machine (a VM, but this shouldn't matter):

=====================&<=============================================
  Cleanup          : libvirt-daemon-driver-network-4.6.0-1.fc29.x86_64                          633/752 
Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 253, in callback
    self._elemProgress(key, amount)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 296, in _elemProgress
    _, _, tsi = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: libvirt-daemon

Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 273, in callback
    self._script_start(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 405, in _script_start
    pkg, _, _ = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: libvirt-daemon

...


Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 273, in callback
    self._script_start(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 405, in _script_start
    pkg, _, _ = self._extract_cbkey(key)
  File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 237, in _extract_cbkey
    raise RuntimeError("TransactionItem not found for key: %s" % cbkey)
RuntimeError: TransactionItem not found for key: libvirt-daemon

  Cleanup          : gdb-headless-8.1.90.20180727-44.fc30.x86_64                                635/752 

...

Failed:
  libvirt-daemon-4.1.0-1.fc29.x86_64                                                                    

Error: Transaction failed
=====================>&=============================================

The traceback repeats maybe a 100 times.

It seems I'm left with a duplicate package:
$ rpm -q libvirt-daemon
libvirt-daemon-4.1.0-1.fc29.x86_64
libvirt-daemon-4.7.0-1.fc30.x86_64

I'm setting high severity since this results in a failed transaction.

Comment 2 Zbigniew Jędrzejewski-Szmek 2018-09-12 16:30:31 UTC

*** This bug has been marked as a duplicate of bug 1625259 ***

Comment 3 Adam Williamson 2018-09-13 17:34:59 UTC
I think Zbigniew may have had a pre-existing dupe in his RPM database, and that may be a trigger for the bug.

Note that we end up with libvirt-daemon-4.7.0-1.fc30 in the db, and the transaction logs this:

Cleanup          : libvirt-daemon-driver-network-4.6.0-1.fc29.x86_64                          633/752

to me that looks a lot like the transaction was updating from 4.6.0-1.fc29 to 4.7.0-1.fc30. *But*, the rpm -qa shows this:

$ rpm -q libvirt-daemon
libvirt-daemon-4.1.0-1.fc29.x86_64
libvirt-daemon-4.7.0-1.fc30.x86_64

where'd that 4.1.0-1.fc29 come from, if we were going from 4.6.0-1 to 4.7.0-1 in the transaction?

This suggests to me that *before* the 'dnf update', the RPM db *already* had duplicate entries for 4.1.0-1.fc29 and 4.6.0-1.fc29 , perhaps due to an earlier crashed update or something along those lines. And so perhaps updating a package which *already has* duplicate entries in the DB triggers the TransactionItem bug?