Re: [ZODB-Dev] More exciting ZODB errors ;-)

2005-12-16 Thread Chris Withers 

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 ;-)

2005-12-16 Thread Tim Peters 
[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 ;-)

2005-12-16 Thread Chris Withers 

Tim Peters wrote:


I don't know, but if I were you I'd try running for a while on entirely
different hardware.


This is on a cluster of machines, with the errors not coming from any 
one machine as far as I can see...



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


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.


Damn, I don't think I collector-ised this one, will do tomorrow...

cheers,

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 ;-)

2005-12-15 Thread Dieter Maurer 
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

Re: [ZODB-Dev] More exciting ZODB errors ;-)

2005-12-15 Thread Dieter Maurer 
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

Re: [ZODB-Dev] More exciting ZODB errors ;-)

2005-12-14 Thread Jeremy Hylton 
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:
>
>  =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

RE: [ZODB-Dev] More exciting ZODB errors ;-)

2005-12-14 Thread Tim Peters 
[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:



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 ;-)

2005-12-14 Thread Jeremy Hylton 
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 ;-)

2005-12-14 Thread Tim Peters 
[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