[Zope3-dev] MinimalMemoryStorage test failure in Zope 3

[Tim Peters]

[Marius Gedminas]
> I can reliably reproduce a TransactionError in
> zodb.storage.tests.testmemory
> in testPackWhileWriting in MinimalMemoryTests.  It does not occur every
> time, but when I run the tests in a loop, I get that error in less than
> 30 seconds.
>
> $ python2.2 test.py -Lvv test_memory testPackWhileWriting
> [...]
> testPackWhileWriting (<class
> 'zodb.storage.tests.test_memory.FullMemoryTests'>) ... ok
> testPackWhileWriting (<class
> 'zodb.storage.tests.test_memory.MinimalMemoryTests'>) ...
> CRITICAL:txn:Transaction failed during second phase of two-phase commit
> Traceback (most recent call last):
>   File "/home/users/mg/Zope3/src/transaction/manager.py", line
> 55, in _finishCommit
>     r.commit(txn)
>   File "/home/users/mg/Zope3/src/zodb/connection.py", line 350, in commit
>     self._storage.tpcFinish(txn, self._invalidate_modified)
>   File "/home/users/mg/Zope3/src/zodb/storage/base.py", line 256,
> in tpcFinish
>     self._finish(self._serial)
>   File "/home/users/mg/Zope3/src/zodb/storage/bdbminimal.py",
> line 318, in _finish
>     self._withtxn(self._docommit, self._serial)
>   File "/home/users/mg/Zope3/src/zodb/storage/base.py", line 761,
> in _withtxn
>     ret = meth(txn, *args, **kws)
>   File "/home/users/mg/Zope3/src/zodb/storage/bdbminimal.py",
> line 188, in _docommit
>     srec = cs.set(oid)
>   File "/home/users/mg/Zope3/src/zodb/storage/memory.py", line 233, in set
>     raise db.DBNotFoundError
> DBNotFoundError
> Exception in thread Thread-337:
> Traceback (most recent call last):
>   File "/usr/lib/python2.2/threading.py", line 414, in __bootstrap
>     self.run()
>   File "/home/users/mg/Zope3/src/zodb/storage/tests/packable.py",
> line 295, in run
>     get_transaction().commit()
>   File "/home/users/mg/Zope3/src/transaction/txn.py", line 75, in commit
>     self._manager.commit(self)
>   File "/home/users/mg/Zope3/src/transaction/manager.py", line
> 49, in commit
>     self._finishCommit(txn)
>   File "/home/users/mg/Zope3/src/transaction/manager.py", line
> 183, in _finishCommit
>     super(ThreadedTransactionManager, self)._finishCommit(txn)
>   File "/home/users/mg/Zope3/src/transaction/manager.py", line
> 68, in _finishCommit
>     raise TransactionError(msg)
> TransactionError: Transaction failed during second phase of
> two-phase commit

Barry (Warsaw, the best person to dig into this) is having a hard time
reproducing the problem.  I confirm that I see it on Win2K (ZODB4 + Python
2.2.3).  In addition to the DBNotFoundError you show above, I see another
failure mode, about as often:

CRITICAL:txn:Transaction failed during second phase of two-phase commit
Traceback (most recent call last):
  File "C:\Code\Zope3\src\transaction\manager.py", line 55, in _finishCommit
    r.commit(txn)
  File "C:\Code\Zope3\src\zodb\connection.py", line 350, in commit
    self._storage.tpcFinish(txn, self._invalidate_modified)
  File "C:\Code\Zope3\src\zodb\storage\base.py", line 256, in tpcFinish
    self._finish(self._serial)
  File "C:\Code\Zope3\src\zodb\storage\bdbminimal.py", line 318, in _finish
    self._withtxn(self._docommit, self._serial)
  File "C:\Code\Zope3\src\zodb\storage\base.py", line 761, in _withtxn
    ret = meth(txn, *args, **kws)
  File "C:\Code\Zope3\src\zodb\storage\bdbminimal.py", line 230, in
_docommit
    deltas = self._update_refcounts(deltas, txn)
  File "C:\Code\Zope3\src\zodb\storage\bdbminimal.py", line 236, in
_update_refcounts
    assert refcount >= 0
AssertionError



In either case (i.e., whether the driver dies with

      raise db.DBNotFoundError
or
    assert refcount >= 0

), another thread dies with "Transaction failed during second phase of
two-phase commit".  There's no theory for either failure at this time.