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
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
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
:
transactions waiting: 4
[WARNING] 2012-01-31T08:22:44: (:::83.164.139.135:50977) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:22:44: (:::83.164.139.135:50921) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:00: (:::83.164.139.135:51056) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:01: (:::83.164.139.135:51019) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:01: (:::83.164.139.135:50940) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:01: (:::83.164.139.135:50921) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:01: (:::83.164.139.135:50921) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:02: (:::83.164.139.135:50974) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:02: (:::83.164.139.135:50974) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:02: (:::83.164.139.135:51019) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:50974) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:50940) ('users') queue
lock: transactions waiting: 5
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:51019) ('users') unlock:
transactions waiting: 5
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:50977) ('users') lock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:50977) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:03: (:::83.164.139.135:51019) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:04: (:::83.164.139.135:50921) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:04: (:::83.164.139.135:51056) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:04: (:::83.164.139.135:50974) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:07: (:::83.164.139.135:51056) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:09: (:::83.164.139.135:51019) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T08:23:11: (:::83.164.139.135:50940) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T08:23:11: (:::83.164.139.135:50977) ('users') unlock:
transactions waiting: 4
[WARNING] 2012-01-31T09:02:17: (:::83.164.139.135:50974) ('users') queue
lock: transactions waiting: 4
[WARNING] 2012-01-31T09:02:17: (:::83.164.139.135:50940) ('users') unlock:
transactions waiting: 4
[ERROR] 2012-01-31T09:20:25: (22455) Error raised in delayed method
None
[INFO] 2012-01-31T09:20:25: (:::127.0.0.1:40243) disconnected
On 30.01.2012, at 14:33, Martijn Pieters wrote:
On Mon, Jan 30, 2012 at 14:15, Kaweh Kazemi ka...@me.com wrote:
I believe my output is confusing, because I additionally redirected the
zeopack output into my zeo.log.
Could you not do that? Redirecting the output to a logfile opened by
two processes can lead to unpredictable results. Tell zeo to reopen
the log file by running bin/zeo logreopen and run zeopack without
redirecting the log, then see what's in the logs.
--
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 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
Re: [ZODB-Dev] persistent broken problem
I resolved that problem. The metaclass was screwing things up (opening the storage before the class was created). On 24.02.2010, at 22:32, Kaweh Kazemi wrote: Hi there, started using ZODB3 with a new project of mine and I've encountered a problem, I couldn't find a solution for so far. I'm adding instances of a class User to a storage (FileStorage for now). I did this in a small test program which worked fine. But then I started to refactor components out of the test program into a module hirarchie and I'm encountering persistent broken instances now. 1) First run: no database nor users created yet, creating a FileStorage, adding 3 users to the database will yield something like this (output within the tester after the work has been done): [rp.framework.user.User object at 0x1016986e0, rp.framework.user.User object at 0x101698758, rp.framework.user.User object at 0x101698848] 2) Second run: reopening previous database, adding 3 new users to the database will yield something like this (output within the tester after the work has been done): [persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x02', persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x04', persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x05', rp.framework.user.User object at 0x1017ad410, rp.framework.user.User object at 0x1017adc80, rp.framework.user.User object at 0x1017adde8] 3) Subsequent runs will add three users with the same output, just the number of persistent broken users is incorrect. Now I understand that a class is broken if the import of that class during opening of the database fails. But I'm doing the runs without changes in between the runs, no changes to the module structure or code and running the exactly same tester (which just re-opens the database and add three new instances). I digged deeper into ZODB.broken to better understand what is happening when the module is imported for a storage. It seems that while opening the database the import of the same module gives slightly different results than later in the script when adding new users. I wonder if that's related to my module structure, which looks similiar to this: rp/ __init__.py framework/ __init__.py ... user.py - this holds the class User, which is a subclass of Entity (see below) odb/ __init__.py ... entity.py - this holds the class Entity, which does a couple of general things for my implementation, which is a subclass of Persistent; class Entity has a class EntityMeta as it's __metaclass__ to handle some magic for me (very similar to what Elixier does for SQLAlchemy, but not that sophisticated) I'm not doing anything in the __init__.py (so I'm not mangeling the module imports in any way, it's just a pure, very young structure I'm building up). The tester is outside of the rp module and just does a from rp.framework.user import User, always the exact same import and still I get the same issue. I tried a couple of tricks in the __init__.py things, or changing sys.path, sys.modules, or even PYTHONPATH, but to no avail. One thing I still wonder is, when exactly find_module is called? Is it called when opening the storage (which happens in my EntityMeta class, so during the creation of the Entity class - and that might ruin everything), or when an object is accessed the first time? Can this behaviour be controlled? I'm quite certain I miss something quite obvious, but I'm stuck. Any hints appreciated. Cheers, Kaweh ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
[ZODB-Dev] persistent broken problem
Hi there, started using ZODB3 with a new project of mine and I've encountered a problem, I couldn't find a solution for so far. I'm adding instances of a class User to a storage (FileStorage for now). I did this in a small test program which worked fine. But then I started to refactor components out of the test program into a module hirarchie and I'm encountering persistent broken instances now. 1) First run: no database nor users created yet, creating a FileStorage, adding 3 users to the database will yield something like this (output within the tester after the work has been done): [rp.framework.user.User object at 0x1016986e0, rp.framework.user.User object at 0x101698758, rp.framework.user.User object at 0x101698848] 2) Second run: reopening previous database, adding 3 new users to the database will yield something like this (output within the tester after the work has been done): [persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x02', persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x04', persistent broken rp.framework.user.User instance '\x00\x00\x00\x00\x00\x00\x00\x05', rp.framework.user.User object at 0x1017ad410, rp.framework.user.User object at 0x1017adc80, rp.framework.user.User object at 0x1017adde8] 3) Subsequent runs will add three users with the same output, just the number of persistent broken users is incorrect. Now I understand that a class is broken if the import of that class during opening of the database fails. But I'm doing the runs without changes in between the runs, no changes to the module structure or code and running the exactly same tester (which just re-opens the database and add three new instances). I digged deeper into ZODB.broken to better understand what is happening when the module is imported for a storage. It seems that while opening the database the import of the same module gives slightly different results than later in the script when adding new users. I wonder if that's related to my module structure, which looks similiar to this: rp/ __init__.py framework/ __init__.py ... user.py - this holds the class User, which is a subclass of Entity (see below) odb/ __init__.py ... entity.py - this holds the class Entity, which does a couple of general things for my implementation, which is a subclass of Persistent; class Entity has a class EntityMeta as it's __metaclass__ to handle some magic for me (very similar to what Elixier does for SQLAlchemy, but not that sophisticated) I'm not doing anything in the __init__.py (so I'm not mangeling the module imports in any way, it's just a pure, very young structure I'm building up). The tester is outside of the rp module and just does a from rp.framework.user import User, always the exact same import and still I get the same issue. I tried a couple of tricks in the __init__.py things, or changing sys.path, sys.modules, or even PYTHONPATH, but to no avail. One thing I still wonder is, when exactly find_module is called? Is it called when opening the storage (which happens in my EntityMeta class, so during the creation of the Entity class - and that might ruin everything), or when an object is accessed the first time? Can this behaviour be controlled? I'm quite certain I miss something quite obvious, but I'm stuck. Any hints appreciated. Cheers, Kaweh ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
