[zope2-tracker] [Bug 394756] [NEW] A simple acces to zmi erase data in a mounted FileStorage

Mon Jul 6 13:52:03 EDT 2009

You have been subscribed to a public bug:

Hello,

Yesterday, when I access to an zeoclient by zmi I loose an zodb file
storage located in a zodb mount point.

<zodb_db media>
  #mount-point /media
  mount-point /PCI/pci/media:/media/PCI/pci/media

  # ZODB cache, in number of objects
  cache-size 10000
  <zeoclient>
    server ....:9090
    storage media
    name zeostorage
    var E:\pci\parts\zopeinstance/var
    # ZEO client cache, in bytes
    cache-size 500MB
  </zeoclient>
</zodb_db>

All data in the storage disappear (I have a structure of simple folder)!
The transaction wich is responsable by that is name manage_menu !!
When I pack the fs , the size pass to ~10K (before 1,4Giga). 

The undo log give this information :

>>> print storage.undoLog(0,10)
[{'description': '/PCI/manage_menu\n\nCreated Zope Application', 'size': 1700L,
'user_name': 'PCI admin', 'id': 'A38ME6PrywA=', 'time': 1246457498.4189997}, {'d
escription': '', 'size': 3713980L, 'user_name': '', 'id': 'A374GPxhwgA=', 'time'
: 1246237019.152}, ....

And  in Z2.log we have this request :

127.0.0.1 - admin [01/Jul/2009:16:11:34 +0200] "GET /PCI/manage_main
HTTP/1.1" 200 122524 "" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT
5.2; SV1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152;
.NET CLR 3.5.30729)"

127.0.0.1 - admin [01/Jul/2009:16:11:28 +0200] "GET /manage_menu
HTTP/1.1" 200 0 "http://localhost:8090/manage" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.2; SV1; .NET CLR 1.1.4322; .NET CLR 2.0.50727;
.NET CLR 3.0.4506.2152; .NET CLR 3.5.30729)"

and in Event.log :

2009-07-01T16:11:31 ERROR Zope.ZODBMountPoint Failed to mount database. exceptions.KeyError (275923683)
Traceback (most recent call last):
  File "E:\Zope\2.9.8\Zope\lib\python\Products\ZODBMountPoint\MountedObject.py", line 258, in _getOrOpenObject
    root = conn.root()
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\Connection.py", line 293, in root
    return self.get(z64)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\Connection.py", line 201, in get
    p, serial = self._storage.load(oid, self._version)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\ClientStorage.py", line 746, in load
    return self.loadEx(oid, version)[:2]
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\ClientStorage.py", line 774, in loadEx
    self._cache.store(oid, ver, tid, None, data)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 293, in store
    self.fc.add(o)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 980, in add
    available = self._makeroom(size)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 915, in _makeroom
    size, e = self.filemap.pop(ofs)
KeyError: 275923683
------
2009-07-01T16:11:31 ERROR ZODB.Connection Couldn't load state for 0x00
Traceback (most recent call last):
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\Connection.py", line 732, in setstate
    self._setstate(obj)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\Connection.py", line 786, in _setstate
    self._reader.setGhostState(obj, p)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\serialize.py", line 604, in setGhostState
    state = self.getState(pickle)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\serialize.py", line 597, in getState
    return unpickler.load()
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\serialize.py", line 471, in _persistent_load
    return self.load_oid(reference)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\serialize.py", line 537, in load_oid
    return self._conn.get(oid)
  File "E:\Zope\2.9.8\Zope\lib\python\ZODB\Connection.py", line 201, in get
    p, serial = self._storage.load(oid, self._version)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\ClientStorage.py", line 746, in load
    return self.loadEx(oid, version)[:2]
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\ClientStorage.py", line 774, in loadEx
    self._cache.store(oid, ver, tid, None, data)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 293, in store
    self.fc.add(o)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 980, in add
    available = self._makeroom(size)
  File "E:\Zope\2.9.8\Zope\lib\python\ZEO\cache.py", line 915, in _makeroom
    size, e = self.filemap.pop(ofs)
KeyError: 275923683
------
2009-07-01T16:11:38 CRITICAL txn.9272 A storage error occurred during the second phase of the two-phase commit.  Resources may be in an inconsistent state.
------
2009-07-01T16:11:38 ERROR Zope.SiteErrorLog http://localhost:8090/PCI/manage_menu
Traceback (innermost last):
  Module ZPublisher.Publish, line 121, in publish
  Module Zope2.App.startup, line 267, in commit
  Module transaction._manager, line 96, in commit
  Module transaction._transaction, line 380, in commit
  Module transaction._transaction, line 378, in commit
  Module transaction._transaction, line 441, in _commitResources
  Module ZODB.Connection, line 679, in tpc_finish
  Module ZEO.ClientStorage, line 974, in tpc_finish
  Module ZEO.ClientStorage, line 1005, in _update_cache
  Module ZEO.cache, line 293, in store
  Module ZEO.cache, line 980, in add
  Module ZEO.cache, line 915, in _makeroom
KeyError: 275923683

To be exact, there is a cron job every night that do some heavy operation on this client. There is memory error on some job since three days. I think there is an relation about my problem but I don't understand how the commit in the fs succeed.
How can I loose data in acceded to the zmi interface ? If you have an explanation it was wonderfull .

** Affects: zope2
     Importance: Undecided
         Status: New

-- 
A simple acces to zmi erase data in a mounted FileStorage
https://bugs.launchpad.net/bugs/394756
You received this bug notification because you are a member of Zope 2 Developers, which is subscribed to Zope 2.