[ZODB-Dev] zeopack error in zrpc.connection
I noticed my DB had swelled to 132 gigabytes (as of 3 days ago; it's 160 gigabytes today) and it seems to be because zeopack has started failing: tsa@sp2772c:~/db$ /home/tsa/env/bin/zeopack -u /home/tsa/db/zeo.sock Traceback (most recent call last): File /home/tsa/env/lib/python2.6/site-packages/ZEO/scripts/zeopack.py, line 159, in _main cs.pack(packt, wait=True) File /home/tsa/env/lib/python2.6/site-packages/ZEO/ClientStorage.py, line 916, in pack return self._server.pack(t, wait) File /home/tsa/env/lib/python2.6/site-packages/ZEO/ServerStub.py, line 155, in pack self.rpc.call('pack', t, wait) File /home/tsa/env/lib/python2.6/site-packages/ZEO/zrpc/connection.py, line 730, in call raise inst # error raised by server TypeError: 'NoneType' object does not support item assignment Error: Error packing storage 1 in '/home/tsa/db/zeo.sock' The runzeo log is: 2013-01-07T11:29:11 INFO ZEO.StorageServer new connection : ManagedServerConnection -- 2013-01-07T11:29:11 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101' -- 2013-01-07T11:29:11 INFO ZEO.StorageServer pack(time=1357576151.4019079) started... -- 2013-01-07T11:55:37 ERROR ZEO.zrpc (8174) Error raised in delayed method None -- 2013-01-07T11:55:37 INFO ZEO.StorageServer disconnected The zeo.conf is: %define INSTANCE . zeo address $INSTANCE/zeo.sock read-only false invalidation-queue-size 100 pid-filename $INSTANCE/zeo.pid /zeo blobstorage 1 filestorage path $INSTANCE/Data.fs /filestorage blob-dir $INSTANCE/blobs /blobstorage I tried shutting down the server that uses the database and re-running zeopack, but the same thing happened. I also tried re-starting 'runzeo' and re-running the pack (with the server still off), and the same thing happened yet again. How do I go about fixing this? Let me know if I can provide any other information that would be helpful. Thanks in advance, - Claudiu ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error in zrpc.connection
How do I go about fixing this? Let me know if I can provide any other information that would be helpful. I took the advice in this thread: https://mail.zope.org/pipermail/zodb-dev/2012-January/014526.html The exception that comes up, from the zeo server log, is: 2013-01-07T13:01:49 ERROR ZEO.zrpc (14891) Error raised in delayed method Traceback (most recent call last): File /home/tsa/env/lib/python2.6/site-packages/ZEO/StorageServer.py, line 1377, in run result = self._method(*self._args) File /home/tsa/env/lib/python2.6/site-packages/ZEO/StorageServer.py, line 343, in _pack_impl self.storage.pack(time, referencesf) File /home/tsa/env/lib/python2.6/site-packages/ZODB/blob.py, line 796, in pack result = unproxied.pack(packtime, referencesf) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/FileStorage.py, line 1078, in pack pack_result = self.packer(self, referencesf, stop, gc) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/FileStorage.py, line 1034, in packer opos = p.pack() File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 397, in pack self.gc.findReachable() File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 190, in findReachable self.findReachableAtPacktime([z64]) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 275, in findReachableAtPacktime for oid in self.findrefs(pos): File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 328, in findrefs return self.referencesf(self._file.read(dh.plen)) File /home/tsa/env/lib/python2.6/site-packages/ZODB/serialize.py, line 630, in referencesf u.noload() TypeError: 'NoneType' object does not support item assignment I'm afraid this doesn't seem to help me figure out what's wrong... - Claudiu ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error in zrpc.connection
On Mon, Jan 7, 2013 at 1:04 PM, Claudiu Saftoiu csaft...@gmail.com wrote: How do I go about fixing this? Let me know if I can provide any other information that would be helpful. I took the advice in this thread: https://mail.zope.org/pipermail/zodb-dev/2012-January/014526.html The exception that comes up, from the zeo server log, is: 2013-01-07T13:01:49 ERROR ZEO.zrpc (14891) Error raised in delayed method Traceback (most recent call last): File /home/tsa/env/lib/python2.6/site-packages/ZEO/StorageServer.py, line 1377, in run result = self._method(*self._args) File /home/tsa/env/lib/python2.6/site-packages/ZEO/StorageServer.py, line 343, in _pack_impl self.storage.pack(time, referencesf) File /home/tsa/env/lib/python2.6/site-packages/ZODB/blob.py, line 796, in pack result = unproxied.pack(packtime, referencesf) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/FileStorage.py, line 1078, in pack pack_result = self.packer(self, referencesf, stop, gc) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/FileStorage.py, line 1034, in packer opos = p.pack() File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 397, in pack self.gc.findReachable() File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 190, in findReachable self.findReachableAtPacktime([z64]) File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 275, in findReachableAtPacktime for oid in self.findrefs(pos): File /home/tsa/env/lib/python2.6/site-packages/ZODB/FileStorage/fspack.py, line 328, in findrefs return self.referencesf(self._file.read(dh.plen)) File /home/tsa/env/lib/python2.6/site-packages/ZODB/serialize.py, line 630, in referencesf u.noload() TypeError: 'NoneType' object does not support item assignment I'm afraid this doesn't seem to help me figure out what's wrong... I suspect your database is corrupted. You'd probably want to look at the record in question to be sure. You could disable garbage collection, but if you have a damaged record, you might want to use the previous version of the record (if it exists) to recover it. Jim -- Jim Fulton http://www.linkedin.com/in/jimfulton Jerky is better than bacon! http://zo.pe/Kqm ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error in zrpc.connection
I'm afraid this doesn't seem to help me figure out what's wrong... I suspect your database is corrupted. You'd probably want to look at the record in question to be sure. Sure, I've re-run the pack and will dump the pickled object to a file to inspect it - is that what you meant? (How else would I figure out what the record is?) You could disable garbage collection, but if you have a damaged record, you might want to use the previous version of the record (if it exists) to recover it. What do you mean by disable garbage collection - you mean disable removing old versions of records that are no longer used? I can't do that unfortunately, the database gets too large. How would I go about attempting to find the previous version of the record? If I know what the record is I can just decide whether to let it be lost - would catching the TypeError and 'pass'ing accomplish that? Thanks, - Claudiu ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
I'm sorry I haven't had time to look at this. Still don't really. Thanks Marius!!! On Wed, Feb 8, 2012 at 6:48 PM, Marius Gedminas mar...@gedmin.as wrote: On Thu, Feb 09, 2012 at 01:25:48AM +0200, Marius Gedminas wrote: On Wed, Feb 08, 2012 at 01:24:55PM +0100, Kaweh Kazemi wrote: Recap: last week I examined problems I had packing our 4GB users storage. ... unp = pickle.Unpickler(f) unp.persistent_load = lambda oid: 'persistent reference %r' % oid pprint.pprint(unp.load()) {'data': {persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\tT', class '__main__.Tool')]: 1, persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\x12\\x03', class '__main__.EnergyPack')]: 1}} Note the reference to __main__. This is almost certainly the root problem. Classes shouldn't be defined in __main__ (except when experimenting). At one time, I thought pickle disallowed pickling classes from __main__. ZODB probably should. It's a bug magnet. Those look like cross-database references to me. The original error (aaaugh Mutt makes it hard for me to look upthread while I'm writing a response) was something about non-hashable lists? Looks like a piece of code is trying to put persistent references into a dict, which can't possibly work in all cases. ... During my checks I realized that running the pack in a Python 2.7 environment (using the same ZODB version - 3.10.3) works fine, the pack reduces our 4GB storage to 1GB. But our production server uses Python 2.6 (same ZODB3.10.3) which yields the problem (though the test had been done on OS X 10.7.3 - 64bit, and the production server is Debian Squeeze 32bit). I've no idea why running the same ZODB version on Python 2.7 instead of 2.6 would make this error go away. Duh! The code that fails is in the standard library -- in the cPickle module: Traceback (most recent call last): ... File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/FileStorage/fspack.py, line 328, in findrefs return self.referencesf(self._file.read(dh.plen)) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/serialize.py, line 630, in referencesf u.noload() TypeError: unhashable type: 'list' Since the bug is in the stdlib, it's not surprising that the newer stdlib cPickle from Python 2.7 fixes it. I suspect a bug in the application (defining persistent classes in __main__) is the root problem that's aggravated by the cPickle problem. That was fun. I'm glad. :) Thanks. Jim -- Jim Fulton http://www.linkedin.com/in/jimfulton ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On 9 February 2012 11:24, Jim Fulton j...@zope.com wrote: I'm sorry I haven't had time to look at this. Still don't really. Thanks Marius!!! On Wed, Feb 8, 2012 at 6:48 PM, Marius Gedminas mar...@gedmin.as wrote: On Thu, Feb 09, 2012 at 01:25:48AM +0200, Marius Gedminas wrote: On Wed, Feb 08, 2012 at 01:24:55PM +0100, Kaweh Kazemi wrote: Recap: last week I examined problems I had packing our 4GB users storage. ... unp = pickle.Unpickler(f) unp.persistent_load = lambda oid: 'persistent reference %r' % oid pprint.pprint(unp.load()) {'data': {persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\tT', class '__main__.Tool')]: 1, persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\x12\\x03', class '__main__.EnergyPack')]: 1}} Note the reference to __main__. This is almost certainly the root problem. Classes shouldn't be defined in __main__ (except when experimenting). At one time, I thought pickle disallowed pickling classes from __main__. ZODB probably should. It's a bug magnet. Those look like cross-database references to me. The original error (aaaugh Mutt makes it hard for me to look upthread while I'm writing a response) was something about non-hashable lists? Looks like a piece of code is trying to put persistent references into a dict, which can't possibly work in all cases. ... During my checks I realized that running the pack in a Python 2.7 environment (using the same ZODB version - 3.10.3) works fine, the pack reduces our 4GB storage to 1GB. But our production server uses Python 2.6 (same ZODB3.10.3) which yields the problem (though the test had been done on OS X 10.7.3 - 64bit, and the production server is Debian Squeeze 32bit). I've no idea why running the same ZODB version on Python 2.7 instead of 2.6 would make this error go away. Duh! The code that fails is in the standard library -- in the cPickle module: Traceback (most recent call last): ... File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/FileStorage/fspack.py, line 328, in findrefs return self.referencesf(self._file.read(dh.plen)) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/serialize.py, line 630, in referencesf u.noload() TypeError: unhashable type: 'list' Since the bug is in the stdlib, it's not surprising that the newer stdlib cPickle from Python 2.7 fixes it. I suspect a bug in the application (defining persistent classes in __main__) is the root problem that's aggravated by the cPickle problem. The pickle's classes were defined in a normal module, I think Marius just aliased those to modules to __main__ and defined the classes there in order to load the pickle without the original code: sys.modules['game.objects.item'] = sys.modules['__main__'] # hack sys.modules['game.objects'] = sys.modules['__main__'] # hack sys.modules['game'] = sys.modules['__main__'] # hack Laurence ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
I suspect a bug in the application (defining persistent classes in __main__) is the root problem that's aggravated by the cPickle problem. The pickle's classes were defined in a normal module, I think Marius just aliased those to modules to __main__ and defined the classes there in order to load the pickle without the original code: sys.modules['game.objects.item'] = sys.modules['__main__'] # hack sys.modules['game.objects'] = sys.modules['__main__'] # hack sys.modules['game'] = sys.modules['__main__'] # hack That's correct, we don't define classes in __main__. All our classes are in their own modules and are imported. Kind regards, Kaweh ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Thu, Feb 09, 2012 at 02:26:10AM +0100, Kaweh Kazemi wrote: Thanks a lot for the investigation, Marius. That was awesome. Seems to me, I need to upgrade to Python 2.7 and be done with the problem then. :/ I wonder, though, if ZODB ought to use the 'noload' method of cPickle.Unpickler, which is undocumented and broken on 2.6 (and gone on 3.x, AFAIU). Incidentally, since you use cross-database references, please make sure they continue to work after you pack your storage. I've lost data that way (the ZODB garbage collector doesn't see references that exist in other storages, and can assume objects are garbage when it shouldn't). Packing with GC disabled ought to be safe. Cross-database references are only one-way in our implementation. users storage is referencing objects in the game storage - never vice versa / no circles. Also we make sure we never delete any objects in *any* storage, just disable them on an application level. This worked fine so far. Are you seeing any problems with this? I don't use cross-database references. My only encounter with them was on Zope 2.x: I uploaded a new version of a website from a .zexp file into /temp_folder, tested it briefly there, then used the ZMI to move it into /. It worked fine for a day, and was broken the next day. Turns out /temp_folder in Zope 2 uses a different backend storage, and moving the folder to root just created a cross-db reference, but didn't move the objects across. Then the garbage collector for the /temp_folder storage noticed that my site was not directly reachable from /temp_folder's root dict, and collected it away as garbage. I do now know if that bug is still present in any version of Zope or ZODB; I just learned not to trust cross-db references. Once burned twice shy, as they say. I'm not saying you will encounter any garbage-collection related problems; I'm saying I would double-check to be sure if I was in your position. Disabling GC during pack works (and was a workaround for a while), but the difference between non-GC (4G) and GC pack (1GB) are 3GB, which is quite a lot and growing too fast. We just don't need all the references from old object states to persist. Packing always removes old object states. Garbage collection also removes new object states for objects that are no longer reachable. Does zeopack consider cross-database references correctly when it checks for reachability? I would hope so, but I don't really know. It would only work if you're packing all the storages together, presumably. Marius Gedminas -- Well, there's a quantum computer that can factor 15, so those of you using 4-bit RSA should worry. -- Bruce Schneier signature.asc Description: Digital signature ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Thu, Feb 9, 2012 at 11:32 AM, Marius Gedminas mar...@gedmin.as wrote: On Thu, Feb 09, 2012 at 02:26:10AM +0100, Kaweh Kazemi wrote: Thanks a lot for the investigation, Marius. That was awesome. Seems to me, I need to upgrade to Python 2.7 and be done with the problem then. :/ I wonder, though, if ZODB ought to use the 'noload' method of cPickle.Unpickler, which is undocumented and broken on 2.6 (and gone on 3.x, AFAIU). noload exists for ZODB. We ZC (DC at the time) wrote cPickle because ZODB needed a highly-optimized pickler. There are a number of decisions we made specifically with ZODB in mind. I don't think the Python 3 version of cPickle reflects these priorities. I strongly suspect we'll end up having our own cPickle in the long run. ... I don't use cross-database references. Cross-database references are definitely an advanced feature that can lead to trouble. When used correctly, they can be very useful. .. Does zeopack consider cross-database references correctly when it checks for reachability? I would hope so, but I don't really know. It would only work if you're packing all the storages together, presumably. zeopack only works on a single storage and thus can't take cross-database references into account. See http://pypi.python.org/pypi/zc.zodbdgc Perhaps this should be included in ZODB 3.11. Jim -- Jim Fulton http://www.linkedin.com/in/jimfulton ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Thu, Feb 9, 2012 at 11:32 AM, Marius Gedminas mar...@gedmin.as wrote: On Thu, Feb 09, 2012 at 02:26:10AM +0100, Kaweh Kazemi wrote: Thanks a lot for the investigation, Marius. That was awesome. Seems to me, I need to upgrade to Python 2.7 and be done with the problem then. :/ I wonder, though, if ZODB ought to use the 'noload' method of cPickle.Unpickler, which is undocumented and broken on 2.6 (and gone on 3.x, AFAIU). noload exists for ZODB. We ZC (DC at the time) wrote cPickle because ZODB needed a highly-optimized pickler. There are a number of decisions we made specifically with ZODB in mind. I don't think the Python 3 version of cPickle reflects these priorities. I strongly suspect we'll end up having our own cPickle in the long run. It would be wonderful if ZODB settled on an internal version of cPickle that didn't use recursion so we could Pickler.dump() OFS.File objects bigger than 32mb :-) Cheers, Darryl Dixon Winterhouse Consulting Ltd http://www.winterhouseconsulting.com ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Feb 9, 2012, at 12:24 PM, Darryl Dixon - Winterhouse Consulting wrote: On Thu, Feb 9, 2012 at 11:32 AM, Marius Gedminas mar...@gedmin.as wrote: On Thu, Feb 09, 2012 at 02:26:10AM +0100, Kaweh Kazemi wrote: Thanks a lot for the investigation, Marius. That was awesome. Seems to me, I need to upgrade to Python 2.7 and be done with the problem then. :/ I wonder, though, if ZODB ought to use the 'noload' method of cPickle.Unpickler, which is undocumented and broken on 2.6 (and gone on 3.x, AFAIU). noload exists for ZODB. We ZC (DC at the time) wrote cPickle because ZODB needed a highly-optimized pickler. There are a number of decisions we made specifically with ZODB in mind. I don't think the Python 3 version of cPickle reflects these priorities. I strongly suspect we'll end up having our own cPickle in the long run. It would be wonderful if ZODB settled on an internal version of cPickle that didn't use recursion so we could Pickler.dump() OFS.File objects bigger than 32mb :-) Shouldn't we just update OFS.File to use blob storage? David -- David Glick Web Developer davidgl...@groundwire.org 206.286.1235x32 Engagement technology for social and environmental change. http://www.groundwire.org ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
Hi there, Recap: last week I examined problems I had packing our 4GB users storage. With Martijn's help I was able to fix zeo's exception output and write out the first broken pickle that throws an exception. During my checks I realized that running the pack in a Python 2.7 environment (using the same ZODB version - 3.10.3) works fine, the pack reduces our 4GB storage to 1GB. But our production server uses Python 2.6 (same ZODB3.10.3) which yields the problem (though the test had been done on OS X 10.7.3 - 64bit, and the production server is Debian Squeeze 32bit). Currently I see only three ways to resolve that problem: - Upgrade production server from Python 2.6 to Python 2.7 which would probably solve the current problem (if it's really a Python 2.6/2.7 problem). - Pack the storage with Python 2.7/ZODB3.10.3 on the working system and deploy it back to the Python 2.6 production environment - very time consuming (because I have to download/pack/upload a big storage and during that time the production server wouldn't be available to avoid changes during that time)/ potentially risky(?). - Find out what is broken regarding that pickle and possibly the Python 2.6/ZODB3.10.3 combination and deploy a fix. You can download the broken pickle from here: http://www.reversepanda.com/download/brokenpickle If someone has more experience in parsing and understanding pickles in regards to ZODB3, any help would be appreciated. Kind regards, Kaweh ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Wed, Feb 08, 2012 at 01:24:55PM +0100, Kaweh Kazemi wrote: Recap: last week I examined problems I had packing our 4GB users storage. With Martijn's help I was able to fix zeo's exception output and write out the first broken pickle that throws an exception. ... You can download the broken pickle from here: http://www.reversepanda.com/download/brokenpickle If someone has more experience in parsing and understanding pickles in regards to ZODB3, any help would be appreciated. I don't have much experience here, but I love a puzzle import pickletools f = open('brokenpickle', 'rb') A ZODB record consists of two pickles: the first stores the class of the object, the other stores the state of the object pickletools.dis(f) 0: cGLOBAL 'rp.odb.containers EntityMapping' 33: qBINPUT 1 35: .STOP highest protocol among opcodes = 1 pickletools.dis(f) 36: }EMPTY_DICT 37: qBINPUT 2 39: USHORT_BINSTRING 'data' 45: qBINPUT 3 47: }EMPTY_DICT 48: qBINPUT 4 50: (MARK 51: ]EMPTY_LIST 52: qBINPUT 5 54: (MARK 55: USHORT_BINSTRING 'm' 58: (MARK 59: USHORT_BINSTRING 'game' 65: qBINPUT 6 67: USHORT_BINSTRING '\x00\x00\x00\x00\x00\x00\tT' 77: qBINPUT 7 79: cGLOBAL 'game.objects.item Tool' 103: qBINPUT 8 105: tTUPLE (MARK at 58) 106: qBINPUT 9 108: eAPPENDS(MARK at 54) 109: QBINPERSID 110: KBININT11 112: ]EMPTY_LIST 113: qBINPUT 10 115: (MARK 116: USHORT_BINSTRING 'm' 119: (MARK 120: hBINGET 6 122: USHORT_BINSTRING '\x00\x00\x00\x00\x00\x00\x12\x03' 132: qBINPUT 11 134: cGLOBAL 'game.objects.item EnergyPack' 164: qBINPUT 12 166: tTUPLE (MARK at 119) 167: qBINPUT 13 169: eAPPENDS(MARK at 115) 170: QBINPERSID 171: KBININT11 173: uSETITEMS (MARK at 50) 174: sSETITEM 175: .STOP highest protocol among opcodes = 1 No secret calls to instantiate 'os.system' with 'rm -rf' as an argument, so I feel safe to try and unpickle it ;-) import sys, pickle, pprint sys.modules['rp.odb.containers'] = sys.modules['__main__'] # hack sys.modules['rp.odb'] = sys.modules['__main__'] # hack sys.modules['rp'] = sys.modules['__main__'] # hack class EntityMapping(object): pass ... f.seek(0) pickle.load(f) class '__main__.EntityMapping' (this is a good place to do a f.tell() and remember the position -- 36 in this case -- so you can f.seek(36) as you iterate trying to make the second pickle load) sys.modules['game.objects.item'] = sys.modules['__main__'] # hack sys.modules['game.objects'] = sys.modules['__main__'] # hack sys.modules['game'] = sys.modules['__main__'] # hack class Tool(object): pass ... class EnergyPack(object): pass ... unp = pickle.Unpickler(f) unp.persistent_load = lambda oid: 'persistent reference %r' % oid pprint.pprint(unp.load()) {'data': {persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\tT', class '__main__.Tool')]: 1, persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\x12\\x03', class '__main__.EnergyPack')]: 1}} Those look like cross-database references to me. The original error (aaaugh Mutt makes it hard for me to look upthread while I'm writing a response) was something about non-hashable lists? Looks like a piece of code is trying to put persistent references into a dict, which can't possibly work in all cases. See ZODB.serialize.ObjectReader._persistent_load for the canonical parser of the various possible formats. ZODB.ConflictResolution.PersistentReference.__init__ is much clearer, though perhaps a tiny bit less canonical. During my checks I realized that running the pack in a Python 2.7 environment (using the same ZODB version - 3.10.3) works fine, the pack reduces our 4GB storage to 1GB. But our production server uses Python 2.6 (same ZODB3.10.3) which yields the problem (though the test had been done on OS X 10.7.3 - 64bit, and the production server is Debian Squeeze 32bit). I've no idea why running the same ZODB version on Python 2.7 instead of 2.6 would make this error go away. Incidentally, since you use cross-database references, please make sure they continue to work after you pack your storage. I've lost data
Re: [ZODB-Dev] zeopack error
On Thu, Feb 09, 2012 at 01:25:48AM +0200, Marius Gedminas wrote: On Wed, Feb 08, 2012 at 01:24:55PM +0100, Kaweh Kazemi wrote: Recap: last week I examined problems I had packing our 4GB users storage. ... unp = pickle.Unpickler(f) unp.persistent_load = lambda oid: 'persistent reference %r' % oid pprint.pprint(unp.load()) {'data': {persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\tT', class '__main__.Tool')]: 1, persistent reference ['m', ('game', '\\x00\\x00\\x00\\x00\\x00\\x00\\x12\\x03', class '__main__.EnergyPack')]: 1}} Those look like cross-database references to me. The original error (aaaugh Mutt makes it hard for me to look upthread while I'm writing a response) was something about non-hashable lists? Looks like a piece of code is trying to put persistent references into a dict, which can't possibly work in all cases. ... During my checks I realized that running the pack in a Python 2.7 environment (using the same ZODB version - 3.10.3) works fine, the pack reduces our 4GB storage to 1GB. But our production server uses Python 2.6 (same ZODB3.10.3) which yields the problem (though the test had been done on OS X 10.7.3 - 64bit, and the production server is Debian Squeeze 32bit). I've no idea why running the same ZODB version on Python 2.7 instead of 2.6 would make this error go away. Duh! The code that fails is in the standard library -- in the cPickle module: Traceback (most recent call last): ... File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/FileStorage/fspack.py, line 328, in findrefs return self.referencesf(self._file.read(dh.plen)) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZODB/serialize.py, line 630, in referencesf u.noload() TypeError: unhashable type: 'list' Since the bug is in the stdlib, it's not surprising that the newer stdlib cPickle from Python 2.7 fixes it. Looks like it was this one: http://bugs.python.org/issue1101399 (hg changeset 56532:d0f005e6fadd) When I diff Modules/cPickle.c between the 2.6 and 2.7 branches in the hg repository, I see that noload() handles the APPEND, APPENDS, SETITEM and SETITEMS differently in 2.7. hg blame attributes that change to 56532. The SETITEM/SETITEMS opcode in the pickle now no longer tries to actually stuff anything into any dicts, which is why the list never ends up being hashed, which explains the error and why it is gone. The fix is present in 2.7, but not in 2.6 That was fun. Marius Gedminas -- Critical sections are Windows's lightweight alternative to mutexes, thus cleverly getting more use out of a previously well-defined phrase by using it to mean something related to but slightly different from the earlier general understanding -- Verity Stob signature.asc Description: Digital signature ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
To debug the pickle, I copied the 4.7GB users.fs to my local machine. I changed the code as proposed by Martijn, started zeo und zeopack - hours later - everything was packed without any troubles. I was puzzled. I then realized that I was running the whole thing with Python 2.7.1 on my local machine (OS X 10.7, 64bit), while the original zeo server was running on Python 2.6.6. (Debian, 32bit). I will rerun the test on my local machine with Python 2.6 and see if I can reproduce the problem. Kind regards, Kaweh On 31.01.2012, at 14:51, Kaweh Kazemi wrote: Thanks Martijn, I'll try to dump the pickle, and see what I can find out. I'm still puzzled how this/what was pickled in the first place. ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
Yes, I did that, unfortunately without avail. I don't get more than a None (see below). Our ZEO configuration inludes this: eventlog logfile path logs/zeo.log format [%(levelname)s] %(asctime)s: %(message)s /logfile /eventlog Do I miss something in the eventlog section that prevents ZEO to output more information? Kind regards, Kaweh [INFO] 2012-01-31T08:00:02: (:::127.0.0.1:40243) pack(time=1327993202.4521811) started... [WARNING] 2012-01-31T08:21:52: (:::83.164.139.135:50974) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:21:53: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:30: (:::83.164.139.135:50974) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:31: (:::83.164.139.135:51019) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:32: (:::83.164.139.135:51019) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:35: (:::83.164.139.135:50974) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:35: (:::83.164.139.135:50977) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:35: (:::83.164.139.135:51056) ('users') queue lock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:51056) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:51056) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:50921) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:51056) ('users') queue lock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:51019) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:50940) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:50940) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:36: (:::83.164.139.135:50940) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:51019) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:51019) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50921) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50977) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50977) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50940) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:37: (:::83.164.139.135:50940) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:38: (:::83.164.139.135:50974) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:38: (:::83.164.139.135:50974) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:38: (:::83.164.139.135:50940) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:39: (:::83.164.139.135:51056) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:40: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:40: (:::83.164.139.135:50977) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:40: (:::83.164.139.135:50921) ('users') queue lock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:41: (:::83.164.139.135:50974) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:41: (:::83.164.139.135:51056) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:42: (:::83.164.139.135:50974) ('users') queue lock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:42: (:::83.164.139.135:51056) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:42: (:::83.164.139.135:50921) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:43: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:43: (:::83.164.139.135:51056) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:43: (:::83.164.139.135:50940) ('users') queue lock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:43: (:::83.164.139.135:50974) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-31T08:22:43: (:::83.164.139.135:50977) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-31T08:22:44: (:::83.164.139.135:50977) ('users') unlock:
Re: [ZODB-Dev] zeopack error
On Tue, Jan 31, 2012 at 12:23, Kaweh Kazemi ka...@me.com wrote: [ERROR] 2012-01-31T09:20:25: (22455) Error raised in delayed method None Ugh, a quick look at the code reveals that this must've been raised by a SlowMethodThread handler, and it indeed doesn't provide the exception info in the log because that's already been cleared. However, the method that does the logging does get passed the exception info (it is after all, partially passed back to the packing script). Could you open ZEO/zrpc/connection.py and edit line 54, the context looks like this: def error(self, exc_info): self.sent = 'error' log(Error raised in delayed method, logging.ERROR, exc_info=True) self.conn.return_error(self.msgid, *exc_info[:2]) If you do not know where that file is located, search for the ZODB3 egg path in your bin/zeo file, that's the directory where you'll find the ZEO code. Change exc_info=True to exc_info=exc_info, so the error method looks like this: def error(self, exc_info): self.sent = 'error' log(Error raised in delayed method, logging.ERROR, exc_info=exc_info) self.conn.return_error(self.msgid, *exc_info[:2]) Restart your ZEO server and attempt to pack again. Now it should log the exception instead of None. -- Martijn Pieters ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Tue, Jan 31, 2012 at 14:20, Kaweh Kazemi ka...@me.com wrote: I did the change and here we go: Right, that's a ZEO bug report right there then; my change should go into ZEO trunk. Jim, did you catch it? I have one assumption - seeing this traceback - but I can't prove if it's correct: one old object (which is candidate to be removed) in the users storage is referencing an object in a different storage (we are using multiple databases) which has been packed away previously. Generally that shouldn't happen, but maybe we have wrongly deleted objects from the second storage and packed it previously. I think the assumption is incorrect; the method referencesf has the following docstring: Return a list of object ids found in a pickle A list may be passed in, in which case, information is appended to it. Only ordinary internal references are included. Weak and multi-database references are not included. Note that weak and multi-database refs are ignored here. A unhashable type error generally means you are trying to use a list (a mutable, thus unhashable type) as a key in a dictionary. So, in this case it is trying to load a pickle record that shouldn't be physically possible in Python; one where a list is used as a key in a dict. I am a little at a loss on how to continue from here. You could rig the .unload() calls in referencesf (in ZODB/serialize) with a try: except TypeError handler: u.persistent_load = refs try: u.noload() u.noload() except TypeError: pass That'll result in a shorter references list, and thus the risk that too many records will be garbage collected. If you are lucky, the type error is at the end of the pickle and thus not many references will be missed, and/or the missed references point to objects that are about to be packed away anyway. Alternatively, you could dump the pickle in question (variable p) to a file instead of passing: except TypeError: open('/tmp/b0rkenpickle', 'wb').write(p) raise Then upload that pickle somewhere for people on this list to analyze. I cannot promise anyone will, of course, but if someone could and the pickle is shown to only contain primitive data types (no references at all) then the pass is certainly going to solve your problem. -- Martijn Pieters ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
[ZODB-Dev] zeopack error
Hi zodb-dev, during our latest zeopack runs, zeopack for our users storage fails giving this error: Traceback (most recent call last): File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/scripts/zeopack.py, line 159, in _main cs.pack(packt, wait=True) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ClientStorage.py, line 916, in pack return self._server.pack(t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ServerStub.py, line 155, in pack self.rpc.call('pack', t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/zrpc/connection.py, line 768, in call raise inst # error raised by server TypeError: unhashable type: 'list' Error: Error packing storage users in ('localhost', 9100) Any ideas how to start to debug this behavior to find the bad data structure that prevents zeopack to run correctly? There is no verbose mode with zeopack as far as I know that would provide me with more helpful information (like the transaction id?). Maybe I can use any of the other tools to get to the source of the problem? Any experience you could share to help me find the bad structure is very much appreciated. Thanks for your help. Kind regards, Kaweh ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
Unfortunately I'm not seeing anything useful, which is my problem: [ERROR] 2012-01-30T13:36:18: (22455) Error raised in delayed method None Traceback (most recent call last): File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/scripts/zeopack.py, line 159, in _main cs.pack(packt, wait=True) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ClientStorage.py, line 916, in pack return self._server.pack(t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ServerStub.py, line 155, in pack self.rpc.call('pack', t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/zrpc/connection.py, line 768, in call raise inst # error raised by server TypeError: unhashable type: 'list' Error: Error packing storage users in ('localhost', 9100) [INFO] 2012-01-30T13:36:18: (:::127.0.0.1:58682) disconnected Kind regards, Kaweh On 30.01.2012, at 12:10, Jim Fulton wrote: On Mon, Jan 30, 2012 at 5:22 AM, Kaweh Kazemi ka...@me.com wrote: Hi zodb-dev, during our latest zeopack runs, zeopack for our users storage fails giving this error: Traceback (most recent call last): File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/scripts/zeopack.py, line 159, in _main cs.pack(packt, wait=True) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ClientStorage.py, line 916, in pack return self._server.pack(t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ServerStub.py, line 155, in pack self.rpc.call('pack', t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/zrpc/connection.py, line 768, in call raise inst # error raised by server TypeError: unhashable type: 'list' Error: Error packing storage users in ('localhost', 9100) Any ideas how to start to debug this behavior to find the bad data structure that prevents zeopack to run correctly? There is no verbose mode with zeopack as far as I know that would provide me with more helpful information (like the transaction id?). Maybe I can use any of the other tools to get to the source of the problem? Any experience you could share to help me find the bad structure is very much appreciated. Thanks for your help. Start by looking for an error in the server log. Jim -- Jim Fulton http://www.linkedin.com/in/jimfulton ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On Mon, Jan 30, 2012 at 13:41, Kaweh Kazemi ka...@me.com wrote: Unfortunately I'm not seeing anything useful, which is my problem: That's because that's not the ZEO server log output, but the output from zeopack. Your ZEO server keeps logs too, Jim is asking for the information you'll find there. -- Martijn Pieters ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] zeopack error
On 30.01.2012, at 14:01, Martijn Pieters wrote: On Mon, Jan 30, 2012 at 13:41, Kaweh Kazemi ka...@me.com wrote: Unfortunately I'm not seeing anything useful, which is my problem: That's because that's not the ZEO server log output, but the output from zeopack. Your ZEO server keeps logs too, Jim is asking for the information you'll find there. I believe my output is confusing, because I additionally redirected the zeopack output into my zeo.log. I get INFO/WARNING/ERROR loggings from zeo into zeo.log (you can see when 127.0.0.1:58682 starts the pack and after the error gets disconnected). Here are some more parts. And as far as I can see an Error is raised in delayed method, but I have no more information in my log. I might be missing something - can I ask zeo to be more verbose about it's doings? [INFO] 2012-01-30T12:20:22: new connection (':::127.0.0.1', 58681): ManagedServerConnection (':::127.0.0.1', 58681) [INFO] 2012-01-30T12:20:22: new connection (':::127.0.0.1', 58682): ManagedServerConnection (':::127.0.0.1', 58682) [INFO] 2012-01-30T12:20:22: new connection (':::127.0.0.1', 58683): ManagedServerConnection (':::127.0.0.1', 58683) [INFO] 2012-01-30T12:20:22: (:::127.0.0.1:58682) received handshake 'Z3101' [INFO] 2012-01-30T12:20:22: (unconnected) disconnected [INFO] 2012-01-30T12:20:22: (unconnected) disconnected [INFO] 2012-01-30T12:20:22: (:::127.0.0.1:58682) pack(time=1327922422.871784) started... [WARNING] 2012-01-30T12:31:28: (:::83.164.139.135:51056) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-30T12:31:41: (:::83.164.139.135:50921) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-30T12:31:41: (:::83.164.139.135:50921) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-30T13:36:13: (:::83.164.139.135:50977) ('users') unlock: transactions waiting: 5 [WARNING] 2012-01-30T13:36:13: (:::83.164.139.135:50940) ('users') lock: transactions waiting: 4 [WARNING] 2012-01-30T13:36:13: (:::83.164.139.135:50940) ('users') unlock: transactions waiting: 4 [WARNING] 2012-01-30T13:36:17: (:::83.164.139.135:50977) ('users') queue lock: transactions waiting: 4 [WARNING] 2012-01-30T13:36:17: (:::83.164.139.135:51019) ('users') unlock: transactions waiting: 4 [ERROR] 2012-01-30T13:36:18: (22455) Error raised in delayed method None Traceback (most recent call last): File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/scripts/zeopack.py, line 159, in _main cs.pack(packt, wait=True) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ClientStorage.py, line 916, in pack return self._server.pack(t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/ServerStub.py, line 155, in pack self.rpc.call('pack', t, wait) File /usr/local/lib/python2.6/dist-packages/ZODB3-3.10.3-py2.6-linux-i686.egg/ZEO/zrpc/connection.py, line 768, in call raise inst # error raised by server TypeError: unhashable type: 'list' Error: Error packing storage users in ('localhost', 9100) [INFO] 2012-01-30T13:36:18: (:::127.0.0.1:58682) disconnected Kind regards, Kaweh ___ For more information about ZODB, see http://zodb.org/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev