zodb / relstorage

A backend for ZODB that stores pickles in a relational database.
Other
53 stars 46 forks source link

tpc_abort cleanup can fail on unexpected exceptions #464

Closed jamadden closed 3 years ago

jamadden commented 3 years ago
Module nti.transactions.loop:761 in __handle_generic_exception
>>  _reraise(*exc_info)
Module nti.transactions.loop:666 in __loop
>>  sleep_time,
Module nti.transactions.loop:73 in _do_commit
>>  tx.nti_commit()
Module perfmetrics._metric:66 in perfmetrics._metric._AbstractMetricImpl.__call__
Module transaction._transaction:282 in commit
>>  reraise(t, v, tb)
Module transaction._transaction:273 in commit
>>  self._commitResources()
Module transaction._transaction:456 in _commitResources
>>  reraise(t, v, tb)
Module transaction._transaction:433 in _commitResources
>>  rm.tpc_vote(self)
Module ZODB.Connection:692 in tpc_vote
>>  s = vote(transaction)
Module perfmetrics._metric:87 in perfmetrics._metric._AbstractMetricImpl.__call__
Module relstorage.storage:499 in tpc_vote
>>  self.tpc_abort(transaction, _force=True)
Module perfmetrics._metric:87 in perfmetrics._metric._AbstractMetricImpl.__call__
Module relstorage.storage:530 in tpc_abort
>>  self._tpc_phase = self._tpc_phase.tpc_abort(transaction, _force)
Module relstorage.storage.tpc:364 in tpc_abort
>>  self.shared_state.abort(force)
Module relstorage.storage.tpc:258 in abort
>>  self.__cleanup('abort_function', (force,))
Module relstorage.storage.tpc:255 in __cleanup
>>  raise Exception("Failed to close one or more resources: %s" % (exceptions,))
Exception: Failed to close one or more resources: [TypeError("'_LazyResource' object is not callable",)]

That's this block: we're dealing with some exception and fail to clean up: https://github.com/zodb/relstorage/blob/af4a63ef516ca2f2bd989532c4960f4f1de70565/src/relstorage/storage/__init__.py#L496-L500

We're clearly in an unexpected state of some sort. The existing tests don't produce this. The report comes from Python 2, so the source of the original exception is lost.

reported by @jzuech3

jamadden commented 3 years ago

Turns out to be a ConflictError:

  File "//RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/storage/__init__.py", line 497, in tpc_vote
    next_phase = self._tpc_phase.tpc_vote(self, transaction)
  File "///RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/storage/tpc/begin.py", line 95, in tpc_vote
    next_phase.enter(storage)
  File "///RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/storage/tpc/vote.py", line 155, in enter
    resolved_in_vote_oid_ints = self._vote(storage)
  File "///RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/storage/tpc/vote.py", line 259, in _vote
    invalidated_oid_ints = self.__check_and_resolve_conflicts(storage, conflicts)
   - __traceback_info__: (<StoreConnection at 0x7f2bfb42fbd0 active=True description={'backend_pid': 98887} conn=<connection object at 0x7f2bfda936e0; dsn: 'user=… application_name
='RS: Store' host=...', closed: 0> cur=<cursor object at 0x7f2bf6e84850; closed: 0>>, <cursor object at 0x7f2bf6e84850; closed: 0>)
  File "///RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/_util.py", line 294, in f
    result = func(*args, **kwargs)
  File "///RelStorage-3.4.3-py2.7-linux-x86_64.egg/relstorage/storage/tpc/vote.py", line 424, in __check_and_resolve_conflicts
    newpickle, committedData)
   - __traceback_info__: (17, set([]))
  File "///ZODB-5.6.0-py2.7.egg/ZODB/ConflictResolution.py", line 297, in tryToResolveConflict
    data=newpickle)
ConflictError: database conflict error (oid 0x392fc1, class BTrees.OOBTree.OOSet, serial this txn started with 0x03df92b3bd0a8c99 2021-04-23 14:11:44.306533, serial currently committed 0x03df92b66db84555 2021-0
4-23 14:14:25.715580)