Bug 495087

Summary: TypeError: rpmdb open failed
Product: [Fedora] Fedora Reporter: Russell Harrison <fedora>
Component: yumAssignee: Seth Vidal <skvidal>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: low    
Version: 11CC: alex, azelinka, caillon, darfoboarioterme, f1r3phoenix, ffesti, james.antill, jnovy, kuba.urbanowicz, mail.for.bugs, ma, marc.stammbach, maxamillion, mnowak, pmatilai, rajeshravin93, rhughes, rmpogorzelski, t.chrzczonowicz, tenshi.lvrz, tim.lauridsen, tuplad
Target Milestone: ---Keywords: Patch
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-06-30 16:28:31 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Russell Harrison 2009-04-09 17:35:46 UTC
Description of problem:
While reviewing the latest set of updates in PackageKit today I started getting an error telling me the yum back end couldn't open the rpmdb.  I get same error running yum from the command line now.  I suspect that I may have caused some sort of a race to the rpmdb by clicking on one updated package and then a second one quickly afterward in the review window.  I can do queries using the rpm command directly however.

Version-Release number of selected component (if applicable):
yum-3.2.21-2.fc10.noarch
rpm-python-4.6.0-1.fc10.i386
rpm-libs-4.6.0-1.fc10.i386
rpm-4.6.0-1.fc10.i386
PackageKit-glib-0.3.14-1.fc10.i386
PackageKit-yum-plugin-0.3.14-1.fc10.i386
PackageKit-udev-helper-0.3.14-1.fc10.i386
PackageKit-yum-0.3.14-1.fc10.i386
PackageKit-0.3.14-1.fc10.i386

  
Here is the error I get now from any yum comand:

rpmdb: Thread/process 16507/3086059200 failed: Thread died in Berkeley DB library
error: db4 error(-30975) from dbenv->failchk: DB_RUNRECOVERY: Fatal error, run database recovery
error: cannot open Packages index using db3 -  (-30975)
error: cannot open Packages database in /var/lib/rpm
Traceback (most recent call last):
  File "/usr/bin/yum", line 29, in <module>
    yummain.user_main(sys.argv[1:], exit_code=True)
  File "/usr/share/yum-cli/yummain.py", line 229, in user_main
    errcode = main(args)
  File "/usr/share/yum-cli/yummain.py", line 84, in main
    base.getOptionsConfig(args)
  File "/usr/share/yum-cli/cli.py", line 184, in getOptionsConfig
    enabled_plugins=self.optparser._splitArg(opts.enableplugins))
  File "/usr/lib/python2.5/site-packages/yum/__init__.py", line 192, in _getConfig
    self._conf = config.readMainConfig(startupconf)
  File "/usr/lib/python2.5/site-packages/yum/config.py", line 774, in readMainConfig
    yumvars['releasever'] = _getsysver(startupconf.installroot, startupconf.distroverpkg)
  File "/usr/lib/python2.5/site-packages/yum/config.py", line 844, in _getsysver
    idx = ts.dbMatch('provides', distroverpkg)
TypeError: rpmdb open failed

Comment 1 Russell Harrison 2009-04-09 17:55:10 UTC
I have confirmed that stale rpmdb locks seem to have been the cause.  rpmdb_stat did show 3 current locks to the database even though no rpm or yum commands were running.  removing the /var/lib/rpm/__db.00* files seems to have cleared up the issue.  I guess the real issue is why yum (or package kit) is leaving the stale locks behind.  A more descriptive error message for this situation would be very helpful as well.

Comment 2 J.U. 2009-04-15 08:01:00 UTC
The same happened for me. While trying to install an rpm using gpk-application 2.27.1. It started after I did 'yum --nogpgcheck update' to the latest rawhide on Apr. 14 09:
Error Type: <type 'exceptions.TypeError'>
Error Value: rpmdb open failed
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2800, in <module>
    main()
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2796, in main
    backend = PackageKitYumBackend('', lock=True)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 196, in __init__
    self.yumbase = PackageKitYumBase(self)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2739, in __init__
    self.repos.confirm_func = self._repo_gpg_confirm
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 643, in <lambda>
    repos = property(fget=lambda self: self._getRepos(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 448, in _getRepos
    self.conf # touch the config class first
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 649, in <lambda>
    conf = property(fget=lambda self: self._getConfig(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 239, in _getConfig
    self._conf = config.readMainConfig(startupconf)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 794, in readMainConfig
    yumvars['releasever'] = _getsysver(startupconf.installroot, startupconf.distroverpkg)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 867, in _getsysver
    idx = ts.dbMatch('provides', distroverpkg)

Comment 3 Michal Nowak 2009-04-21 08:33:34 UTC
*** Bug 496590 has been marked as a duplicate of this bug. ***

Comment 4 Michal Nowak 2009-04-21 08:36:41 UTC
Same for me with today's Rawhide update via PackageKit (gpk-update-viewer):


Error Type: <type 'exceptions.TypeError'>
Error Value: rpmdb open failed
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2800, in <module>
    main()
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2796, in main
    backend = PackageKitYumBackend('', lock=True)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 196, in __init__
    self.yumbase = PackageKitYumBase(self)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2739, in __init__
    self.repos.confirm_func = self._repo_gpg_confirm
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 643, in <lambda>
    repos = property(fget=lambda self: self._getRepos(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 448, in _getRepos
    self.conf # touch the config class first
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 649, in <lambda>
    conf = property(fget=lambda self: self._getConfig(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 239, in _getConfig
    self._conf = config.readMainConfig(startupconf)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 794, in readMainConfig
    yumvars['releasever'] = _getsysver(startupconf.installroot, startupconf.distroverpkg)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 867, in _getsysver
    idx = ts.dbMatch('provides', distroverpkg)

Comment 5 Ales Zelinka 2009-04-21 09:53:36 UTC
I have this problem too. It seems to me more like a rpm/db4 bug, but as this report already exists...

After a daily update via gpk, yum tracebacks and rpm stops working. After that every rpm command exits with this error:

rpmdb: Thread/process 18327/140308284557040 failed: Thread died in Berkeley DB library
error: db4 error(-30974) from dbenv->failchk: DB_RUNRECOVERY: Fatal error, run database recovery
error: cannot open Packages index using db3 -  (-30974)
error: cannot open Packages database in /var/lib/rpm
rpmdb: Thread/process 18327/140308284557040 failed: Thread died in Berkeley DB library
error: db4 error(-30974) from dbenv->failchk: DB_RUNRECOVERY: Fatal error, run database recovery
error: cannot open Packages database in /var/lib/rpm


After deleting /var/lib/rpm/__db.00{0,1} rpm starts to work again. (I usually follow with rpm --rebuilddb) Restart also seems to help (I guess those files get deleted during boot?).

But the problem is back next day. Regularly. For 4 days now.

Comment 6 Panu Matilainen 2009-04-21 12:12:18 UTC
These "Thread died in Berekely DB library" messages are not a problem in themselves, they are a sanity-check telling you that the *previous* run was terminated abnormally while holding the db open (for writing, otherwise the automatic lock cleaner is normally able to fix): either by rpm itself or a librpm API consumer crashing, or getting killed with -9.

So what we need is to find out which rpm related process is dying and why.

Oh and yum should really handle this more gracefully than blowing up with a traceback, rpmdb open can (and does) fail for variety of reasons.

Comment 7 Panu Matilainen 2009-04-21 12:52:19 UTC
*** Bug 490790 has been marked as a duplicate of this bug. ***

Comment 8 James Antill 2009-04-21 13:47:25 UTC
Panu, I did a test patch of:

diff --git a/yum/config.py b/yum/config.py
index d3ace8f..04385dd 100644
--- a/yum/config.py
+++ b/yum/config.py
@@ -861,7 +861,11 @@ def _getsysver(installroot, distroverpkg):
     '''
     ts = rpmUtils.transaction.initReadOnlyTransaction(root=installroot)
     ts.pushVSFlags(~(rpm._RPMVSF_NOSIGNATURES|rpm._RPMVSF_NODIGESTS))
-    idx = ts.dbMatch('provides', distroverpkg)
+    try:
+        idx = ts.dbMatch('provides', distroverpkg)
+    except TypeError, e:
+        # This is code for "cannot open rpmdb"
+        raise Errors.YumBaseError(e.message)
     # we're going to take the first one - if there is more than one of these
     # then the user needs a beating
     if idx.count() == 0:

...which is where everyone seems to hit the problem, the reason I didn't push it upstream was that I couldn't reproduce the problem. If someone who is hitting it can try the above by hand, that'd be useful ... also see what PK does with the above.

Comment 9 Christopher Beland 2009-04-22 17:44:10 UTC
*** Bug 491035 has been marked as a duplicate of this bug. ***

Comment 10 Christopher Beland 2009-04-22 17:57:44 UTC
Reading related bugs and above comments, it appears there are several parallel approaches to remedying this problem:
* Handle the error more gracefully, perhaps with a suggestion to check for other running RPM-related programs and then manually remove the lock if none are running.
* Handle the condition by safely and automatically clearing the stale locks (somehow).
* Better instrument the various programs that get RPM locks, so if they fail badly this can be more easily diagnosed.

FYI, this problem has been encountered at least occasionally in Fedora 9, 10, and Rawhide, so I'm changing the version on the bug to Rawhide, since that is the most recent.

Comment 11 Christopher Beland 2009-04-22 18:00:41 UTC
*** Bug 444241 has been marked as a duplicate of this bug. ***

Comment 12 Christopher Beland 2009-04-22 18:06:25 UTC
*** Bug 489230 has been marked as a duplicate of this bug. ***

Comment 13 Ales Zelinka 2009-04-23 13:18:18 UTC
I've added the exception handling from comment #8 into my config.py and the daily update(via gpk-update*) worked flawlessly, no traceback and no stale locks afterwards.

Comment 14 Panu Matilainen 2009-04-24 07:27:28 UTC
Please note that the patch in comment #8 only affects how the failure to open rpmdb is reported by yum, it does nothing to resolve the cause that lead to this situation.

James, the patch looks reasonable to me (technically every dbMatch() should be prepared to handle exceptions raised but that'll catch the most common case). However it seems that other parts of yum aren't prepared to handle exception here, this is what I get (with upstream 3.2.x branch) with just the patch from comment #8 and rpmdb driven into this state:
# yum update
[...]
rpmdb open failed
Traceback (most recent call last):
  File "./yummain.py", line 316, in <module>
    user_main(sys.argv[1:], exit_code=True)
  File "./yummain.py", line 309, in user_main
    errcode = main(args)
  File "./yummain.py", line 161, in main
    return exFatal(e)
  File "./yummain.py", line 65, in exFatal
    if unlock(): return 200
  File "./yummain.py", line 71, in unlock
    base.doUnlock()
  File "/home/pmatilai/repos/yum/yum/__init__.py", line 1174, in doUnlock
    if hasattr(self, 'preconf') or self.conf.uid != 0:
  File "/home/pmatilai/repos/yum/yum/__init__.py", line 649, in <lambda>
    conf = property(fget=lambda self: self._getConfig(),
  File "/home/pmatilai/repos/yum/yum/__init__.py", line 194, in _getConfig
    fn = self.preconf.fn
AttributeError: 'YumBaseCli' object has no attribute 'preconf'

Here's a reproducer to get rpmdb into this state:
As root, run these two in paraller in two terminals.
1) while [ 1 -eq 1 ]; do rpm -qa; done
2) while [ 1 -eq 1 ]; do sleep 0.2; killall -9 rpm; done

It might take a while or it can happen immediately, just a matter of luck with timing.

Now, the likely *cause* of this is PackageKit being impatient with yumBackend not responding to SIGQUIT fast enough and terminating it with SIGKILL. This is not unlike Russian roulette: sometimes you get away with it (with just stale locks that are automatically purged), sometimes you dont (if you happen to hit it while inside db4 code).

Folks seeing this, please test this PK version: http://koji.fedoraproject.org/koji/taskinfo?taskID=1316602. It no longer sends SIGKILL to the yum backend at all, so IF PackageKit is the only source of these issues, you shouldn't see these rpmdb open failures any more.

Comment 15 Richard Hughes 2009-04-24 10:08:53 UTC
Notice, I've only been able to reproduce this bug using PackageKit on F11 when yum-presto is installed. Uninstall yum-presto and I can't get the rpmdb into a crazy state even when cancelling with SIGKILL.

Either way, I've requested a tag here: https://fedorahosted.org/rel-eng/ticket/1628

Comment 16 seth vidal 2009-05-04 14:38:46 UTC
*** Bug 498341 has been marked as a duplicate of this bug. ***

Comment 17 seth vidal 2009-05-21 14:34:43 UTC
*** Bug 501909 has been marked as a duplicate of this bug. ***

Comment 18 seth vidal 2009-05-21 14:36:05 UTC
*** Bug 496543 has been marked as a duplicate of this bug. ***

Comment 19 Marc Stammbach 2009-05-30 12:32:19 UTC
Similar to comment #2 and #4

rror Type: <type 'exceptions.TypeError'>
Error Value: rpmdb open failed
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2828, in <module>
    main()
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2824, in main
    backend = PackageKitYumBackend('', lock=True)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 196, in __init__
    self.yumbase = PackageKitYumBase(self)
  File : /usr/share/PackageKit/helpers/yum/yumBackend.py, line 2767, in __init__
    self.repos.confirm_func = self._repo_gpg_confirm
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 643, in <lambda>
    repos = property(fget=lambda self: self._getRepos(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 448, in _getRepos
    self.conf # touch the config class first
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 649, in <lambda>
    conf = property(fget=lambda self: self._getConfig(),
  File : /usr/lib/python2.6/site-packages/yum/__init__.py, line 239, in _getConfig
    self._conf = config.readMainConfig(startupconf)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 794, in readMainConfig
    yumvars['releasever'] = _getsysver(startupconf.installroot, startupconf.distroverpkg)
  File : /usr/lib/python2.6/site-packages/yum/config.py, line 867, in _getsysver
    idx = ts.dbMatch('provides', distroverpkg)

Comment 20 Marc Stammbach 2009-05-30 12:46:27 UTC
Additional to comment #19
If I do a "yum update" it gives me an error 

[root@localhost marc]# yum update
Geladene Plugins: refresh-packagekit
rpmdb: Thread/process 26711/140723358365424 failed: Thread died in Berkeley DB library
Fehler: db4-Fehler (-30974) von dbenv->failchk: DB_RUNRECOVERY: Fatal error, run database recovery
Fehler: Kann den Packages-Index nicht öffnen, benutze db3 -  (-30974)
Fehler: Kann Paket-Datenbank in /var/lib/rpm nicht öffnen
Traceback (most recent call last):
  File "/usr/bin/yum", line 29, in <module>
    yummain.user_main(sys.argv[1:], exit_code=True)
  File "/usr/share/yum-cli/yummain.py", line 309, in user_main
    errcode = main(args)
  File "/usr/share/yum-cli/yummain.py", line 157, in main
    base.getOptionsConfig(args)
  File "/usr/share/yum-cli/cli.py", line 187, in getOptionsConfig
    self.conf
  File "/usr/lib/python2.6/site-packages/yum/__init__.py", line 649, in <lambda>
    conf = property(fget=lambda self: self._getConfig(),
  File "/usr/lib/python2.6/site-packages/yum/__init__.py", line 239, in _getConfig
    self._conf = config.readMainConfig(startupconf)
  File "/usr/lib/python2.6/site-packages/yum/config.py", line 794, in readMainConfig
    yumvars['releasever'] = _getsysver(startupconf.installroot, startupconf.distroverpkg)
  File "/usr/lib/python2.6/site-packages/yum/config.py", line 867, in _getsysver
    idx = ts.dbMatch('provides', distroverpkg)
TypeError: rpmdb open failed
[root@localhost marc]#

Comment 21 Marc Stammbach 2009-05-31 07:03:57 UTC
Additional to comment #19

To recover "rpmdb open failed" I have deleted all the __db* files in /var/lib/rpm

After that the update of software run without returning an error and could update.

Comment 22 Bug Zapper 2009-06-09 13:33:30 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 11 development cycle.
Changing version to '11'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 23 Christopher Aillon 2009-06-17 20:02:54 UTC
*** Bug 497397 has been marked as a duplicate of this bug. ***

Comment 24 Adam Miller 2009-06-29 20:20:13 UTC
Is anyone still having this issue since Fedora 11 went stable or is this only in Rawhide? Or potentially not at all?

-Adam

Comment 25 Michal Nowak 2009-06-30 08:09:36 UTC
Quite a long time I've seen it in F-11.

Comment 26 seth vidal 2009-06-30 16:28:31 UTC
okay, if it comes back alive - open a new bug.

Comment 27 Panu Matilainen 2009-07-14 11:39:50 UTC
*** Bug 506836 has been marked as a duplicate of this bug. ***

Comment 28 seth vidal 2009-08-16 12:10:14 UTC
*** Bug 517722 has been marked as a duplicate of this bug. ***