RE: [ZODB-Dev] More exciting ZODB errors ;-)
[Tim] I don't know, but if I were you I'd try running for a while on entirely different hardware. [Chris] This is on a cluster of machines, with the errors not coming from any one machine as far as I can see... Networking gear and cables are also hardware ;-) 10:05 - Couldn't load state for 0x013872b7: Traceback (most recent call ... if not (self._mvcc and self._setstate_noncurrent(obj)): File lib/python/ZODB/Connection.py, line 788, in setstate_noncurrent assert end is not None AssertionError ... Smells like an internal MVCC bug to me. Damn, I don't think I collector-ised this one, will do tomorrow... No need, you already did, and I added Dieter's comments to it yesterday: http://www.zope.org/Collectors/Zope/1971 ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] More exciting ZODB errors ;-)
Tim Peters wrote: This is on a cluster of machines, with the errors not coming from any one machine as far as I can see... Networking gear and cables are also hardware ;-) large bank datacenter - not a chance in hell of sensibly testing this :-( No need, you already did, and I added Dieter's comments to it yesterday: http://www.zope.org/Collectors/Zope/1971 Yup, just noticed :-) Chris -- Simplistix - Content Management, Zope Python Consulting - http://www.simplistix.co.uk ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
RE: [ZODB-Dev] More exciting ZODB errors ;-)
Tim Peters wrote at 2005-12-14 12:05 -0500:
...
return self.rpc.call('tpc_begin', id, user, descr, ext, tid, status)
File lib/python/ZEO/zrpc/connection.py, line 536, in call
raise inst # error raised by server
StorageTransactionError: Multiple simultaneous tpc_begin requests from one
client.
We see this occationally in ZODB 3.2 in the following situation:
From time to time our ZEO (running on Solaris) fails
to create a TemporaryFile (because Solaris raises
an OSError: error 11 -- resource temporarily unavailabe from fdopen).
Apparently, ZEO does not expect this kind of exception and
forgets to remove the lock set for this client.
As a consequence, any further commit trial by this client
results in the Multiple simulataneous tpc_begin... exception.
--
Dieter
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/
ZODB-Dev mailing list - ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev
FW: [ZODB-Dev] More exciting ZODB errors ;-)
FYI, I also added this info to Chris's other bug report, at http://www.zope.org/Collectors/Zope/1971 -Original Message- From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] On Behalf Of Dieter Maurer Sent: Thursday, December 15, 2005 11:52 AM To: Chris Withers Cc: zodb-dev@zope.org Subject: Re: [ZODB-Dev] More exciting ZODB errors ;-) Chris Withers wrote at 2005-12-14 16:23 +: ... File lib/python/ZODB/Connection.py, line 788, in _setstate_noncurrent assert end is not None AssertionError This means that the latest modification for this object lies before the respective transaction. In this case, we should not have an invalidation for the object, such that we would not call _setstate_current. I expect a missing flush_invalidations during Connection._setDB. I had to add such a call in our ZODB version: def _setDB(self, odb, mvcc=None, txn_mgr=DEPRECATED_ARGUMENT, transaction_manager=None, synch=None): self.transaction_manager = transaction_manager or transaction.manager # DM 2005-08-22: always call '_flush_invalidations' as it does # more than cache handling only self._flush_invalidations() if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() # DM 2005-08-22: always call '_flush_invalidations' ##else: ##self._flush_invalidations() -- Dieter ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
FW: [ZODB-Dev] More exciting ZODB errors ;-)
FYI, I added this info to Chris's bug report, at
http://www.zope.org/Collectors/Zope/1970
Thanks!
-Original Message-
From: [EMAIL PROTECTED]
[mailto:[EMAIL PROTECTED] On Behalf Of Dieter Maurer
Sent: Thursday, December 15, 2005 11:02 AM
To: Tim Peters
Cc: 'Chris Withers'; zodb-dev@zope.org
Subject: RE: [ZODB-Dev] More exciting ZODB errors ;-)
Tim Peters wrote at 2005-12-14 12:05 -0500:
...
return self.rpc.call('tpc_begin', id, user, descr, ext, tid, status)
File lib/python/ZEO/zrpc/connection.py, line 536, in call
raise inst # error raised by server
StorageTransactionError: Multiple simultaneous tpc_begin requests from
one
client.
We see this occationally in ZODB 3.2 in the following situation:
From time to time our ZEO (running on Solaris) fails
to create a TemporaryFile (because Solaris raises
an OSError: error 11 -- resource temporarily unavailabe from fdopen).
Apparently, ZEO does not expect this kind of exception and
forgets to remove the lock set for this client.
As a consequence, any further commit trial by this client
results in the Multiple simulataneous tpc_begin... exception.
--
Dieter
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/
ZODB-Dev mailing list - ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev
[ZODB-Dev] More exciting ZODB errors ;-)
Hi All,
We recently upgraded to Zope 2.8.4 and have been seeing some different
and special errors every so often (why does this always and only ever
happen to me? ;-) Nothing noticeably bad appears to result from these,
but, as always, I loose hair over them and would like ot know what's
going on :-S
Any clues?
Chris
08:55 - Traceback (most recent call last):
lib/python/transaction/_transaction.py,
line 422, in _commitResources
rm.tpc_begin(self)
File lib/python/ZODB/Connection.py, line
446, in tpc_begin
self._normal_storage.tpc_begin(transaction)
File lib/python/ZEO/ClientStorage.py,
line 914, in tpc_begin
txn._extension, tid, status)
File lib/python/ZEO/ServerStub.py, line
232, in tpc_begin
return self.rpc.call('tpc_begin', id, user, descr, ext, tid, status)
File lib/python/ZEO/zrpc/connection.py,
line 536, in call
raise inst # error raised by server
StorageTransactionError: Multiple simultaneous tpc_begin requests from one
client.
10:05 - Couldn't load state for 0x013872b7:
Traceback (most recent call last):
File lib/python/ZODB/Connection.py, line
704, in setstate
self._setstate(obj)
File lib/python/ZODB/Connection.py, line
757, in _setstate
self._load_before_or_conflict(obj)
File lib/python/ZODB/Connection.py, line
765, in _load_before_or_conflict
if not (self._mvcc and self._setstate_noncurrent(obj)):
File lib/python/ZODB/Connection.py, line
788, in _setstate_noncurrent
assert end is not None
AssertionError
10:05 - Error viewing a method on an object:
File lib/python/Products/PluginIndexes/DateIndex/DateIndex.py, line
135, in index_object
oldConvertedDate = self._unindex.get( documentId, _marker )
File lib/python/ZODB/Connection.py, line
704, in setstate
self._setstate(obj)
File lib/python/ZODB/Connection.py, line
757, in _setstate
self._load_before_or_conflict(obj)
File lib/python/ZODB/Connection.py, line
765, in _load_before_or_conflict
if not (self._mvcc and self._setstate_noncurrent(obj)):
File lib/python/ZODB/Connection.py, line
788, in _setstate_noncurrent
assert end is not None
AssertionError
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/
ZODB-Dev mailing list - ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev
RE: [ZODB-Dev] More exciting ZODB errors ;-)
[Chris Withers]
We recently upgraded to Zope 2.8.4 and have been seeing some different
and special errors every so often (why does this always and only ever
happen to me? ;-)
I don't know, but if I were you I'd try running for a while on entirely
different hardware.
Nothing noticeably bad appears to result from these, but, as always, I
loose hair over them and would like ot know what's going on :-S
Any clues?
Chris
08:55 - Traceback (most recent call last):
lib/python/transaction/_transaction.py, line 422, in _commitResources
rm.tpc_begin(self)
File lib/python/ZODB/Connection.py, line 446, in tpc_begin
self._normal_storage.tpc_begin(transaction)
File lib/python/ZEO/ClientStorage.py, line 914, in tpc_begin
txn._extension, tid, status)
File lib/python/ZEO/ServerStub.py, line 232, in tpc_begin
return self.rpc.call('tpc_begin', id, user, descr, ext, tid, status)
File lib/python/ZEO/zrpc/connection.py, line 536, in call
raise inst # error raised by server
StorageTransactionError: Multiple simultaneous tpc_begin requests from one
client.
Found only one previous report of this, against Zope 2.6.1, some ZODB 3.0.1
beta (unclear exactly which), and Berkeley DB:
http://mail.zope.org/pipermail/zodb-dev/2003-May/005195.html
Jeremy made some suggestions a few msgs down, but there was no followup from
the OP and no resolution.
10:05 - Couldn't load state for 0x013872b7: Traceback (most recent call
last):
File lib/python/ZODB/Connection.py, line 704, in setstate
self._setstate(obj)
File lib/python/ZODB/Connection.py, line 757, in _setstate
self._load_before_or_conflict(obj)
File lib/python/ZODB/Connection.py, line 765, in
_load_before_or_conflict
if not (self._mvcc and self._setstate_noncurrent(obj)):
File lib/python/ZODB/Connection.py, line 788, in _setstate_noncurrent
assert end is not None
AssertionError
10:05 - Error viewing a method on an object:
File lib/python/Products/PluginIndexes/DateIndex/DateIndex.py, line
135, in index_object
oldConvertedDate = self._unindex.get( documentId, _marker )
File lib/python/ZODB/Connection.py, line 704, in setstate
self._setstate(obj)
File lib/python/ZODB/Connection.py, line 757, in _setstate
self._load_before_or_conflict(obj)
File lib/python/ZODB/Connection.py, line 765, in
load_before_or_conflict
if not (self._mvcc and self._setstate_noncurrent(obj)):
File lib/python/ZODB/Connection.py, line 788, in _setstate_noncurrent
assert end is not None
AssertionError
Haven't seen a report of this before. It's trying to load state for a ghost
object, but the oid has been invalidated, so (because of MVCC) it's trying
to load state that _was_ current at the time the transaction began. The
assertion is griping because the non-current state it loaded doesn't appear
to have a sane validity range (that `end` is None is claiming that the old
state is still valid, but that can't be true if the oid has in fact been
invalidated).
Smells like an internal MVCC bug to me.
Jeremy, the code at the start of _setstate() looks fishy: any idea what the
intent was?:
# There is a harmless data race with self._invalidated. A
# dict update could go on in another thread, but we don't care
# because we have to check again after the load anyway.
if (obj._p_oid in self._invalidated
and not myhasattr(obj, _p_independent)
and not self._invalidated
):
# If the object has _p_independent(), we will handle it below.
self._load_before_or_conflict(obj)
return
Specifically, how could:
obj._p_oid in self._invalidated
and:
not self._invalidated
be true at the same time? The latter says _invalidated is empty, but the
former can't be true if _invalidated is empty. Offhand, then, unless we're
_counting_ on a thread race here ;-), it looks impossible that the body of
this `if` could execute.
I don't have a reason to believe it's directly relevant to Chris's problem,
it's just that I got baffled by the first thing I looked at ;-)
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/
ZODB-Dev mailing list - ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] More exciting ZODB errors ;-)
On 12/14/05, Tim Peters [EMAIL PROTECTED] wrote: Jeremy, the code at the start of _setstate() looks fishy: any idea what the intent was?: # There is a harmless data race with self._invalidated. A # dict update could go on in another thread, but we don't care # because we have to check again after the load anyway. if (obj._p_oid in self._invalidated and not myhasattr(obj, _p_independent) and not self._invalidated ): # If the object has _p_independent(), we will handle it below. self._load_before_or_conflict(obj) return I don't have any idea what the intent of not self._invalidated was. I looked back at 3.3a2, which I think was the first MVCC release. It doesn't have the and not self._invalidated line , and I can't think of why it would. The code is just an optimization; it's trying to avoid loading the current version if it knows that it needs a non-current version. I don't have a checkout of ZODB, so I can't check the svn blame. Does it say who wrote the code and what change it was related to? Jeremy Specifically, how could: obj._p_oid in self._invalidated and: not self._invalidated be true at the same time? The latter says _invalidated is empty, but the former can't be true if _invalidated is empty. Offhand, then, unless we're _counting_ on a thread race here ;-), it looks impossible that the body of this `if` could execute. I don't have a reason to believe it's directly relevant to Chris's problem, it's just that I got baffled by the first thing I looked at ;-) ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
RE: [ZODB-Dev] More exciting ZODB errors ;-)
[Timmy] Jeremy, the code at the start of _setstate() looks fishy: any idea what the intent was?: # There is a harmless data race with self._invalidated. A # dict update could go on in another thread, but we don't care # because we have to check again after the load anyway. if (obj._p_oid in self._invalidated and not myhasattr(obj, _p_independent) and not self._invalidated ): # If the object has _p_independent(), we will handle it below. self._load_before_or_conflict(obj) return [Jeremy] I don't have any idea what the intent of not self._invalidated was. I looked back at 3.3a2, which I think was the first MVCC release. It doesn't have the and not self._invalidated line , and I can't think of why it would. The code is just an optimization; it's trying to avoid loading the current version if it knows that it needs a non-current version. I don't have a checkout of ZODB, so I can't check the svn blame. Does it say who wrote the code and what change it was related to? Congratulations on weaseling out of another one ;-)! Turns out this all happened after your statutory blame period, as part of a large merge to fix ZClasses: http://svn.zope.org/ZODB/branches/3.4/src/ZODB/Connection.py?rev=29891view =rev That introduced the and not self._invalidated clause. We'll fix that one way or another (it doesn't make sense), but I'm pretty sure it's irrelevant to Chris's symptom (it stops an optimization rather than creates a problem). ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] More exciting ZODB errors ;-)
On 12/14/05, Tim Peters [EMAIL PROTECTED] wrote: I don't have a checkout of ZODB, so I can't check the svn blame. Does it say who wrote the code and what change it was related to? Congratulations on weaseling out of another one ;-)! It was much harder to weasel out of them when I actually had commit privileges. Turns out this all happened after your statutory blame period, as part of a large merge to fix ZClasses: http://svn.zope.org/ZODB/branches/3.4/src/ZODB/Connection.py?rev=29891view =rev That introduced the and not self._invalidated clause. We'll fix that one way or another (it doesn't make sense), but I'm pretty sure it's irrelevant to Chris's symptom (it stops an optimization rather than creates a problem). Right. It's certainly going to hurt the performance of ZODB in a high-write situation, because it will always read the current revision of an object, even when it needs a non-current revision. Jeremy ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
