[Zope-dev] [ZEO] protocol problem

Dieter Maurer dieter@handshake.de
Mon, 25 Feb 2002 09:44:36 +0100


Not sure, whether this is the right list. If not, please advise a better
place.

We use Zope 2.5 together with ZEO 1.0b5 and there seems to be
a problem with the communication between Zope and ZEO.

  Several times a day, Zope reports that it has been disconnected form
  storage (a warning), that it tries to reconnect but fails
  due to "error 131, 'Connection reset by peer'".

  ZEO on the other hand reports that it had opened the connection
  and keeps it open until Zope stops.


There is one special setup:

  We check ZEO every minute for availability.
  The script opens a ZEO connection and lets it load an object.

  I have something like a weak impression that connection
  requests coming in at about the same time might confuse ZEO.

Any information would be appreaciated.


Annotated extract from Zope logfile:
====================================

  >  2002-02-24T12:01:09 PROBLEM(100) ClientStorage Disconnected from storage
  >  ------
  >  2002-02-24T12:01:09 INFO(0) client Trying to connect to server: ('ora', 8888)
  >  ------
  >  2002-02-24T12:01:09 ERROR(200) ZODB Couldn't load state for '\x00\x00\x00\x00\x00\t\x08>'
  >  ------
  >  2002-02-24T12:01:09 INFO(0) ClientStorage Connected to storage
  Here we have apparently two log messages intermingled:

    The "ClientStorage Connected" and the "Error: Couldn't load state".
  >  Traceback (innermost last):
  >    File /local/home/zope/Zope/Base/lib/python/ZODB/Connection.py, line 446, in setstate
  >    File /home/zope/Zope-9000/Base/lib/python/ZEO/ClientStorage.py, line 365, in load
  >      (Object: ('ora', 8888))
  >    File /home/zope/Zope-9000/Base/lib/python/ZEO/zrpc.py, line 239, in __call__
  >  error: (131, 'Connection reset by peer')


Annotated extract from ZEO logfile:
===================================

  >  2002-02-24T12:01:08 INFO(0) ZEO Server Close 3501648
  >  ------
  >  2002-02-24T12:01:09 INFO(0) ZEO Server Connect 3501648 ('10.19.3.10', 33017)
  The connection is opened here but only closed 7 hours later when
  Zope stops.
  >  ------
  >  2002-02-24T12:02:09 INFO(0) ZEO Server Connect 3501720 ('10.19.1.129', 64202)
  >  ......
  >  2002-02-24T19:50:43 INFO(0) ZEO Server Close 3501720
  >  ------
  >  2002-02-24T19:51:33 INFO(0) ZEO Server Connect 3501720 ('10.19.3.10', 49795)
  here, Zope has been stopped.
  ZEO releases all "hanging" connections.
  >  ------
  >  2002-02-24T19:51:37 INFO(0) ZEO Server Close 3501648
  >  ------
  >  2002-02-24T19:51:37 INFO(0) ZEO Server Close 3501600
  >  ------
  >  2002-02-24T19:51:37 INFO(0) ZEO Server Close 3501504


Dieter