[ZODB-Dev] bug in ZEO-1.0b3

[Dyon Balding]

Jeremy Hylton wrote:
> 
> >>>>> "DB" == Dyon Balding <dyon@devcoder.com.au> writes:
> 
>   DB> If the ZEO server goes down, the the client no longer tries to
>   DB> keep reconnecting.  This works fine with the ZEO-1.0b1 (I
>   DB> haven't tried b2).
> 
>   DB> This appears to be something to do with the __closed attribute
>   DB> in zrpc.py.  This is set to 1 when the server goes down, and the
>   DB> client only tries to reconnect when it's value is 0.
> 
>   DB> Can anyone else verify this bug?
> 
> I can verify that there is at least one problem here, but I'm not sure
> what its cause is.
> 
> I assume you suspect the closed attribute in ClientStorage, as zrpc
> doesn't have any attribute with close in the name and __closed is part
> of the StorageServer.  I'll admit it as a possibility since it's new,
> but it's only set when the ClientStorage's close() method is called,
> which shouldn't happen when the server goes down.
> 
> If you've got the energy, could you capture a zLOG trace of this
> failure to reconnect?  If there's a "INFO(0) ClientStorage close
> message in the log, then you're probably right.
> 

In ZEO-1.0b3, zrpc.py appears to have a new attribute in asyncRPC,
__closed.
On line 136, it only connects while __closed is 0, but on line 296 when
the
server goes down, __closed is set to 1, and doesn't appear to be reset
to 0.

Below is the STUPID_LOG_FILE, the first Disconnected exception is while
the
storage is stopped, and the second is after it has restarted.  Obviously
the
client hasn't tried to reconnect it though :(.

My custom_zodb.py includes the following:

    Storage=ZEO.ClientStorage.ClientStorage(
        connection=(ZSS_HOST,ZSS_PORT),
        min_disconnect_poll=1,
        max_disconnect_poll=2,
        name=ZSS_NAME)

This works fine with 1.0b1.  It also works fine in 1.0b3 if line 136
in zrpc.py is changed back to a while 1:.

good luck
-d




<STUPID_LOG_FILE>
------
2001-05-30T17:10:12 INFO(0) zdaemon zdaemon: Wed May 30 10:10:12 2001:
Houston, we have forked
------
2001-05-30T17:10:12 INFO(0) zdaemon zdaemon: Wed May 30 10:10:12 2001:
Houston, we have forked
------
2001-05-30T17:10:12 INFO(0) zdaemon zdaemon: Wed May 30 10:10:12 2001:
Hi, I just forked off a kid: 9932
------
2001-05-30T17:10:18 INFO(0) client Trying to connect to server:
('192.168.0.6', 8888)
------
2001-05-30T17:10:18 INFO(0) ClientStorage Connected to storage
------
2001-05-30T17:10:18 BLATHER(-100) ZEC
read_index(/home/dyon/work/hiringtools/zope/zc/var/c1-8080-0.zec)
------
2001-05-30T17:10:27 INFO(0) ZServer HTTP server started at Wed May 30
10:10:27 2001
        Hostname: gormenghast
        Port: 8080
------
2001-05-30T17:10:27 INFO(0) ZServer FTP server started at Wed May 30
10:10:27 2001
        Hostname: gormenghast
        Port: 8021
------
2001-05-30T17:10:51 PROBLEM(100) ClientStorage Disconnected from storage
------
2001-05-30T17:11:12 ERROR(200) ZODB Couldn't load state for
'\000\000\000\000\000\000\001,'
Traceback (innermost last):
  File
/home/dyon/work/hiringtools/zope/zc/lib/python/ZODB/Connection.py, line
508, in setstate
  File
/home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/ClientStorage.py,
line 354, in load
    (Object: ZEOStorage)
  File /home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/zrpc.py, line
209, in __call__
    (Object: dispatcher)
  File /home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/smac.py, line
184, in message_output
    (Object: dispatcher)
Disconnected: This action is temporarily unavailable.<p>


------
2001-05-30T17:12:01 ERROR(200) ZODB Couldn't load state for
'\000\000\000\000\000\000\001,'
Traceback (innermost last):
  File
/home/dyon/work/hiringtools/zope/zc/lib/python/ZODB/Connection.py, line
508, in setstate
  File
/home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/ClientStorage.py,
line 354, in load
    (Object: ZEOStorage)
  File /home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/zrpc.py, line
209, in __call__
    (Object: dispatcher)
  File /home/dyon/work/hiringtools/zope/zc/lib/python/ZEO/smac.py, line
184, in message_output
    (Object: dispatcher)
Disconnected: This action is temporarily unavailable.<p>

</STUPID_LOG_FILE>