Hide Forgot
Description of problem: Tracebacks are printed to the users console for the Runtime error: RuntimeError: TransactionItem not found for key This would be better logged and not spewed onto stdout. Version-Release number of selected component (if applicable): dnf-4.0.10-1.fc30.noarch How reproducible: If package is missing an attribute. Steps to Reproduce: 1. dnf upgrade -y 2. 3. Actual results: Everything installs, but the console is flooded with tracebacks (seen below) Expected results: dnf would report the error and log the traceback Additional info: 2019-02-06T07:59:22Z CRITICAL Traceback (most recent call last): File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 272, in callback self._uninst_progress(amount, total, key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 356, in _uninst_progress transaction_list = self._extract_cbkey(key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 244, in _extract_cbkey raise RuntimeError("TransactionItem not found for key: %s" % cbkey) RuntimeError: TransactionItem not found for key: libcap 2019-02-06T07:59:22Z CRITICAL Traceback (most recent call last): File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 272, in callback self._uninst_progress(amount, total, key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 356, in _uninst_progress transaction_list = self._extract_cbkey(key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 244, in _extract_cbkey raise RuntimeError("TransactionItem not found for key: %s" % cbkey) RuntimeError: TransactionItem not found for key: libcap 2019-02-06T07:59:22Z CRITICAL Traceback (most recent call last): File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 272, in callback self._uninst_progress(amount, total, key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 356, in _uninst_progress transaction_list = self._extract_cbkey(key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 244, in _extract_cbkey raise RuntimeError("TransactionItem not found for key: %s" % cbkey) RuntimeError: TransactionItem not found for key: libcap 2019-02-06T07:59:22Z CRITICAL Traceback (most recent call last): File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 270, in callback self._unInstStop(key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 363, in _unInstStop transaction_list = self._extract_cbkey(key) File "/usr/lib/python3.7/site-packages/dnf/yum/rpmtrans.py", line 244, in _extract_cbkey raise RuntimeError("TransactionItem not found for key: %s" % cbkey) RuntimeError: TransactionItem not found for key: libcap I grabbed these from the log file because I did the update in multi-user mode and couldn't copy paste from my console. But it's the same tracebacks that I was seeing dnf filling my screen with.
I understand why we're raising the Runtime error. But can we maybe just do something like this instead? def _extract_cbkey(self, cbkey): """Obtain the package related to the calling callback.""" try: if hasattr(cbkey, "pkg"): tsi = cbkey return [tsi] te = self._te_list[self._te_index] te_nevra = dnf.util._te_nevra(te) if self._tsi_cache: if str(self._tsi_cache[0]) == te_nevra: return self._tsi_cache items = [] for tsi in self.base.transaction: if tsi.action == libdnf.transaction.TransactionItemAction_REINSTALL: # skip REINSTALL in order to return REINSTALLED continue if str(tsi) == te_nevra: items.append(tsi) if items: self._tsi_cache = items return items raise RuntimeError("TransactionItem not found for key: %s" % cbkey) except RuntimeError as err: logger.error(err)
Brendan, could you provide more information for reproducing the issue? * /var/lib/dnf/history.sqlite * list if installed RPMs: rpm -qa * list of enabled repos: LC_ALL=C dnf repolist --enabled -v | egrep '^Repo-|^$' Eventually if you could create a Dockerfile with a minimal reproducer in docker/podman.
Created attachment 1535031 [details] dnf history sqlite There is an updated version of the traceback in the last dnf transaction - I will provide the dnf.log separately, but it did it during the last transaction which is: 132 | upgrade -y | 2019-02-15 14:16 | E, I, U | 242 EE
Created attachment 1535032 [details] Installed RPM's ( rpm -qa )
Created attachment 1535033 [details] enabled repos
Working on a podman reproducer. Still not sure what's causing it, I just noticed it again today and thought it was a good time to grab the fresh info. I'll keep working on reproducing it in a container.
Created attachment 1535034 [details] dnf.log
*** Bug 1680160 has been marked as a duplicate of this bug. ***
We have an instance of this issue being reported again Fedora 29: https://bugzilla.redhat.com/show_bug.cgi?id=1680160 From what I can see, we're looking at this function: https://github.com/rpm-software-management/dnf/blob/master/dnf/yum/rpmtrans.py#L222-L244 90% of the time, it appears to exit during the first if statement. But in the events where it makes it past, it seems to have nothing to push to the items list: items = [] for tsi in self.base.transaction: if tsi.action == libdnf.transaction.TransactionItemAction_REINSTALL: # skip REINSTALL in order to return REINSTALLED continue if str(tsi) == te_nevra: items.append(tsi) <<< ---- Seems like nothing happens here so items is still null. if items: self._tsi_cache = items return items raise RuntimeError("TransactionItem not found for key: %s" % cbkey) So it must be this part that is failing: te = self._te_list[self._te_index] te_nevra = dnf.util._te_nevra(te) We can try: except: it to remove the traceback from stdout and send it to logger instead. On my original BZ, I suggested a pretty broad try, except, but we could be more specific and just wrap it around the final if statement which should improve user experience. Ultimately, this error doesn't seem to be fatal. But it would be nice to understand what is failing. I haven't started digging into _te_nevra() yet so that's all I have at the moment.
I had no luck reproducing the issue. From my previous experience, it's almost impossible to fix such issues without the reproducer. The code is mix of old YUM's code with new transaction/history code patched into it. We're planning to do couple rewrites to make it saner and make sure we have tests for the important parts.
(In reply to Daniel Mach from comment #10) > I had no luck reproducing the issue. > > From my previous experience, it's almost impossible to fix such issues > without the reproducer. > The code is mix of old YUM's code with new transaction/history code patched > into it. > We're planning to do couple rewrites to make it saner and make sure we have > tests for the important parts. Yeah, I haven't been able to get a consistent reproducer. I saw it happen a couple more times, which seemed to be if I left my laptop for a week or more and then did dnf upgrade. Which I assumed was the difference in package versions. But when I pull the exact same versions of those package into a podman container and run the update I wasn't seeing it. It seems fairly cosmetic to be honest. I haven't experienced any failures or issues as a result of the traceback. Unless there is some other information we think would be useful here, I think we can close this one with insufficient data.
I found a reproducer that may (or may not) be related to this bug. It was related to how dnf computes obsoletes when upgrading multilib packages: https://github.com/rpm-software-management/dnf/pull/1354 If the problem strikes back after this PR is released, I'm hoping in getting a better reproducer and I'll look into it again.
dnf-4.2.5-1.fc29 libdnf-0.31.0-2.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2019-2612a121ba
dnf-4.2.5-1.fc29, libdnf-0.31.0-2.fc29 has been pushed to the Fedora 29 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-2612a121ba
dnf-4.2.5-1.fc29, libdnf-0.31.0-2.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.