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.