[ZODB-Dev] Weird errors with Zope 2.7.7

[Tim Peters]

[Chris Withers]
> We've been seeing these errors for a while now, but had assumed it was
> due to an old Zope version. We've been running 2.7.7 for a week or two
> now and we're still seeing these intermittently:

At any particular time(s)?  For example, do these (either or both) tend to
occur when a ZEO client is starting up?  Shutting down?  In the middle of
their lives?  No correlation?

> ERROR(200) zrpc-conn(C):x.x.x.x:yyyy Asynchronous call raised exception:
> <ManagedClientConnection ('x.x.x.x', yyyy)> Traceback (most recent call
last):
>    File "lib/python/ZEO/zrpc/connection.py",
> line 373, in handle_request
>      ret = meth(*args)
>    File "/lib/python/ZEO/ClientStorage.py",
> line 1111, in invalidateTransaction
>      self._process_invalidations(args)
>    File "lib/python/ZEO/ClientStorage.py",
> line 1074, in _process_invalidations
>      self._cache.invalidate(oid, version=version)
>    File "lib/python/ZEO/ClientCache.py",
> line 297, in invalidate
>      p = self._get(oid, None)
> AttributeError: ClientCache instance has no attribute '_get'
>
> ...which seems a little odd :-S

Peculiar:  in 2002, you called it "weird" instead ;-):

    http://mail.zope.org/pipermail/zodb-dev/2002-December/004091.html

    [Chris Withers]
    [...]
    AttributeError: ClientCache instance has no attribute '_get'

    ...which is weird :-S

    [...]

A ClientCache doesn't have a `_get` attribute when it's first constructed;
for whatever reason, it doesn't get one until ClientCache.open() is called.
I don't see any code capable of removing the `_get` attribute from a
ClientCache after its open() is called, so looks like a safe bet its open()
has never been called.

It looks like open() is "supposed to be" called sometime during initial
cache verification.  That code is complicated.  It would help to have more
of the log context, especially the INFO-level log messages produced by this
ZEO client during startup:  this could be a ZEO startup race, but there are
so many possible paths thru that code that more clues are needed.

> ERROR(200) ZODB Shouldn't load state for 0x6c33b4 when the connection is
closed
>
> ...which is a bit more distrubing.

That one comes out of Connection.setstate(), and appears to mean what it
says:  the app is trying to load an object from this Connection but the
Connection has been closed.  It's far more likely that this one is a bug in
Zope or some product than that it's a bug in ZODB (ZODB simply doesn't _try_
to load objects unless an app tells it to; ditto for opening or closing
connections).

> This is on a ZEO setup with the storage server running a FileStorage and
> a TemporaryStorage on Slowlartis (changing this evening, don't worry!)
> and multiple ZEO clients each running on their own linux box.
>
> Has anyone seen any of the above with 2.7.7?

I haven't seen other reports; the only Google hits on the ClientCache
AttributeError are in messages from you, so that one can't be widespread.