[Zope] ZODB reverts to older state after ZEO restart

[dvs]

Recently we restarted our zeo server and immediately noticed 
that we are missing good bit of recently added content. We seemed 
to have reverted back to a specific date in the past. All content 
updates since have disappeared.

Restoring the Data.fs from a recent backup still had the same effect, the 
content all reverted back to one specific date.  In the logs it does show 
that we restored the Data.fs from a backup, restarted, and migrated to 
a newer version of Zope/Plone (Zope 2.9.4 - 2.9.5, Plone 2.5.4 - 2.5.5). 
After the update, the site was fine and was running along smoothly. 

A few days later this came up in the event.log:

2008-01-24T19:05:44 ERROR ZServer uncaptured python exception, closing
channel <ZServer.HTTPServer.zhttp_channel connected 72.249.81.93:56139 at 0x
1598d92c channel#: 45214 requests:> (socket.error:(54, 'Connection reset by
peer') [/usr/local/lib/python2.4/asynchat.py|initiate_send|219] [/usr/l
ocal/zope/295/lib/python/ZServer/medusa/http_server.py|send|417]
[/usr/local/lib/python2.4/asyncore.py|send|332])
------
2008-01-24T19:05:45 ERROR ZEO.zrpc (27931) can't decode message:
'(M\x06\xdcK\x00U\x06.reply(TC\x00\x01\x00(cOFS.Image\nP...'
------
2008-01-24T19:05:45 ERROR ZEO.zrpc.Connection(C) (127.0.0.1:9999) Error
caught in asyncore
Traceback (most recent call last):
  File "/usr/local/lib/python2.4/asyncore.py", line 69, in read
    obj.handle_read_event()
  File "/usr/local/lib/python2.4/asyncore.py", line 391, in
handle_read_event
    self.handle_read()
  File "/usr/local/zope/295/lib/python/ZEO/zrpc/smac.py", line 219, in
handle_read
    self.message_input(msg)
  File "/usr/local/zope/295/lib/python/ZEO/zrpc/connection.py", line 387, in
message_input
    msgid, flags, name, args = self.marshal.decode(message)
  File "/usr/local/zope/295/lib/python/ZEO/zrpc/marshal.py", line 50, in
decode
    return unpickler.load() # msgid, flags, name, args
MemoryError
------
2008-01-24T19:05:45 INFO ZEO.ClientStorage (27931) Disconnected from
storage: "('xxxxx.com', 9999)"
------
2008-01-24T19:05:45 INFO ZEO.ClientStorage (27931) Testing connection
<ManagedClientConnection ('72.249.81.93', 9999)>
------
2008-01-24T19:05:45 INFO ZEO.zrpc.Connection(C) (127.0.0.1:9999) received
handshake 'Z303'

------
2008-01-24T19:05:45 ERROR ZODB.Connection Couldn't load state for 0x01868c
Traceback (most recent call last):
  File "/usr/local/zope/295/lib/python/ZODB/Connection.py", line 732, in
setstate
    self._setstate(obj)
  File "/usr/local/zope/295/lib/python/ZODB/Connection.py", line 786, in
_setstate
    self._reader.setGhostState(obj, p)
  File "/usr/local/zope/295/lib/python/ZODB/serialize.py", line 604, in
setGhostState
    state = self.getState(pickle)
  File "/usr/local/zope/295/lib/python/ZODB/serialize.py", line 597, in
getState
    return unpickler.load()
  File "/usr/local/zope/295/lib/python/ZODB/serialize.py", line 471, in
_persistent_load
    return self.load_oid(reference)
  File "/usr/local/zope/295/lib/python/ZODB/serialize.py", line 537, in
load_oid
    return self._conn.get(oid)
  File "/usr/local/zope/295/lib/python/ZODB/Connection.py", line 201, in get
    p, serial = self._storage.load(oid, self._version)
  File "/usr/local/zope/295/lib/python/ZEO/ClientStorage.py", line 746, in
load
    return self.loadEx(oid, version)[:2]
  File "/usr/local/zope/295/lib/python/ZEO/ClientStorage.py", line 769, in
loadEx
    data, tid, ver = self._server.loadEx(oid, version)
  File "/usr/local/zope/295/lib/python/ZEO/ServerStub.py", line 192, in
loadEx
    return self.rpc.call("loadEx", oid, version)
  File "/usr/local/zope/295/lib/python/ZEO/zrpc/connection.py", line 531, in
call
    r_flags, r_args = self.wait(msgid)
  File "/usr/local/zope/295/lib/python/ZEO/zrpc/connection.py", line 621, in
wait
    raise DisconnectedError()
DisconnectedError
------

The persistent cache file has been saved, but looking at the archive it
seems that 
you can't restore a Data.fs from the persistent cache (please correct me on
this). Looking at 
the logs we can find what content was edited in this time frame and we can
see that it did exist at one time, but the data itself is not in any of the
backup Data.fs files we have.

This is a bit perplexing in that when we restore from any of the backups it
still reverts, what could 
cause this situation and if the data was in fact being saved, where could it
have been saved? We 
were backing up the correct Data.fs (at least, it was the Data.fs that the
zeo server was connected to)

If the zeo server was read only this would make sense but then we wouldn't
be able to make any 
content updates and it would be immediately evident.

Any suggestions or ideas on how we could recover any of this data and the
reasoning behind this happening is much appreciated. 

-- 
View this message in context: http://www.nabble.com/ZODB-reverts-to-older-state-after-ZEO-restart-tp17264827p17264827.html
Sent from the Zope - General mailing list archive at Nabble.com.