Hi, in our Studentregistration portal we experience many conflict errors under heavy load many of them unresolved. the configuration ZEO-server running on one machine 4 Zope-Clients with CPS-3.4.2 with 4 threads each running on a second box, we are using the faster session product all running Zope 2.9.3, python 2.4.3 on Ubuntu 4.0.3 a typical case looks like this: about 5 or 6 messages in the log file with the oid 0x2b 2007-05-23T17:32:38 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/S882364/study_course/create_level: database conflict error (oid 0x2b, class Products.faster.sessiondata.SessionDataContainer, serial this txn started with 0x036dd29c28404f33 2007-05-23 16:28:09.433877, serial currently committed 0x036dd29ed2491566 2007-05-23 16:30:49.285660) (780 conflicts (73 unresolved) since startup at Wed May 23 05:56:52 2007) and finally ------ 2007-05-23T17:32:38 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/S882364/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 433, in _commitResources Module ZODB.Connection, line 484, in commit Module ZODB.Connection, line 526, in _commit Module ZODB.Connection, line 554, in _store_objects Module tempstorage.TemporaryStorage, line 200, in store ConflictError: database conflict error (oid 0x2b, class Products.faster.sessiondata.SessionDataContainer, serial this txn started with 0x036dd29c28404f33 2007-05-23 16:28:09.433877, serial currently committed 0x036dd29ed2491566 2007-05-23 16:30:49.285660) Even though we have many write operations the write operations can't actually conflict, since each student only works on his own documents. Any hints howto to get further insight into this problem is welcome. -- Gruß Joachim
Joachim Schmitz wrote:
Module tempstorage.TemporaryStorage, line 200, in store ConflictError: database conflict error (oid 0x2b, class Products.faster.sessiondata.SessionDataContainer, serial this txn started with 0x036dd29c28404f33 2007-05-23 16:28:09.433877, serial currently committed 0x036dd29ed2491566 2007-05-23 16:30:49.285660)
Your conflicts are coming from the session machinery. You're likely storing information in there that you shouldn't be ;-) cheers, Chris PS: This question is better targetted at zope@zope.org -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk
You might try placing the session data container in the main ZODB FileStorage (or ZEO storage if you use ZEO) to see if it demonstrates fewer conflicts there than using one contained in a TemporaryStorage. If you use ZEO, you will need to ensure that the Products.faster package can be imported from within the storage server itself (the storage server performs conflict resolution as opposed to each client doing it). On May 23, 2007, at 1:12 PM, Joachim Schmitz wrote:
Hi,
in our Studentregistration portal we experience many conflict errors under heavy load many of them unresolved.
the configuration
ZEO-server running on one machine 4 Zope-Clients with CPS-3.4.2 with 4 threads each running on a second box, we are using the faster session product
all running Zope 2.9.3, python 2.4.3 on Ubuntu 4.0.3
a typical case looks like this: about 5 or 6 messages in the log file with the oid 0x2b
2007-05-23T17:32:38 INFO ZPublisher.Conflict ConflictError at / VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/ campus/students/S882364/study_course/create_level: database conflict error (oid 0x2b, class Products.faster.sessiondata.SessionDataContainer, serial this txn started with 0x036dd29c28404f33 2007-05-23 16:28:09.433877, serial currently committed 0x036dd29ed2491566 2007-05-23 16:30:49.285660) (780 conflicts (73 unresolved) since startup at Wed May 23 05:56:52 2007)
and finally
------ 2007-05-23T17:32:38 ERROR Zope.SiteErrorLog http://uniben.waeup.org/ campus/students/S882364/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 433, in _commitResources Module ZODB.Connection, line 484, in commit Module ZODB.Connection, line 526, in _commit Module ZODB.Connection, line 554, in _store_objects Module tempstorage.TemporaryStorage, line 200, in store ConflictError: database conflict error (oid 0x2b, class Products.faster.sessiondata.SessionDataContainer, serial this txn started with 0x036dd29c28404f33 2007-05-23 16:28:09.433877, serial currently committed 0x036dd29ed2491566 2007-05-23 16:30:49.285660)
Even though we have many write operations the write operations can't actually conflict, since each student only works on his own documents.
Any hints howto to get further insight into this problem is welcome.
-- Gruß Joachim
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Answering to myself: we could get rid of the sessionrelated conflict errors, by removing all session = context.REQUEST.SESSION from our scripts. But we still have these conflict errors: how can I find out, what causes these conflicts. 2007-05-25T10:17:50 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/U431409/study_course/create_level: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) -- and finally: ------ 2007-05-25T10:19:01 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/C172676/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700) ------ Joachim Schmitz schrieb:
Hi,
in our Studentregistration portal we experience many conflict errors under heavy load many of them unresolved.
the configuration
ZEO-server running on one machine 4 Zope-Clients with CPS-3.4.2 with 4 threads each running on a second box, we are using the faster session product
all running Zope 2.9.3, python 2.4.3 on Ubuntu 4.0.3
a typical case looks like this:
-- Gruß Joachim
Perry napisał(a):
Answering to myself:
we could get rid of the sessionrelated conflict errors, by removing all
session = context.REQUEST.SESSION
from our scripts. But we still have these conflict errors:
how can I find out, what causes these conflicts.
2007-05-25T10:17:50 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/U431409/study_course/create_level:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) Try to change session resolution seconds (Timeout resolution (in seconds)) parameter to a larger value. Possibly you're ecountering same problem as I had some time ago. With long requests and small session resolution seconds I had a lot of conflict errors.
I think it is because of way sessions work in zope. Every x seconds (where x is 'session resolution seconds'), when there is access to SESSION, session objects are moved in OOBTrees. It is used to handle session expiration. Not used session objects are moved to the end of the 'list' and finally removed after Session Timeout is reached. I don't know how this exactly goes but it is something like that. When this 'movement' happens during request (session object is moved when request that is bound to it is still being served) this causes conflicts. You may look at group archives for my posts month or two months ago... It is easy to reproduce these errors. -- Maciej Wisniowski
Maciej Wisniowski schrieb:
Perry napisał(a):
Answering to myself:
we could get rid of the sessionrelated conflict errors, by removing all
session = context.REQUEST.SESSION
from our scripts. But we still have these conflict errors:
how can I find out, what causes these conflicts.
2007-05-25T10:17:50 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/U431409/study_course/create_level:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) Try to change session resolution seconds (Timeout resolution (in seconds)) parameter to a larger value. Possibly you're ecountering same problem as I had some time ago. With long requests and small session resolution seconds I had a lot of conflict errors.
I set it now to 9600/4800 (Timeout/Resolution) but it seams that it has no effect.
I think it is because of way sessions work in zope. Every x seconds (where x is 'session resolution seconds'), when there is access to SESSION, session objects are moved in OOBTrees. It is used to handle session expiration. Not used session objects are moved to the end of the 'list' and finally removed after Session Timeout is reached. I don't know how this exactly goes but it is something like that.
When this 'movement' happens during request (session object is moved when request that is bound to it is still being served) this causes conflicts. You may look at group archives for my posts month or two months ago...
I read this already I am also using the faster-session product and patched it to use the AppendOnlyDict. -- Gruß Joachim
I set it now to 9600/4800 (Timeout/Resolution) but it seams that it has no effect. Hm... where did you set this? At faster's preferences page in ZMI? can you verify that these settings are used? To change timeout/resolution to high values for standard session implementation in zope.conf I had to patch one of zope core files, otherwise it was not possible to start zope.
One more thing may be that these errors appears because of large number of newly created session objects, eg. after zope restart. I mean that when you restart zope and then run 10 concurrent requests 10 new session objects will be created. This may (and possibly do) cause conflicts as these are all changes to OOBTree. When you run these 10 concurrent requests again from the same browsers (without restarting zope) then objects are already created so only session resolution may be taken into account I think. How do you check this? One more thing I wonder about is what number of threads your zope instance is running?
I read this already I am also using the faster-session product and patched it to use the AppendOnlyDict. In this case it had no effect for me too.
-- Maciej Wisniowski
Maciej Wisniowski schrieb:
I set it now to 9600/4800 (Timeout/Resolution) but it seams that it has no effect. Hm... where did you set this? At faster's preferences page in ZMI? Yes can you verify that these settings are used? don't know how.
To change timeout/resolution to high values for standard session implementation in zope.conf I had to patch one of zope core files, otherwise it was not possible to start zope.
One more thing may be that these errors appears because of large number of newly created session objects, eg. after zope restart. I mean that when you restart zope and then run 10 concurrent requests 10 new session objects will be created. This may (and possibly do) cause conflicts as these are all changes to OOBTree. When you run these 10 concurrent requests again from the same browsers (without restarting zope) then objects are already created so only session resolution may be taken into account I think.
How do you check this? One more thing I wonder about is what number of threads your zope instance is running? we have 4 Zeo-Clients with 4 threads each accessing one ZEO-Server on a different machine.
-- Gruß Joachim
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Perry wrote:
Answering to myself:
we could get rid of the sessionrelated conflict errors, by removing all
session = context.REQUEST.SESSION
from our scripts. But we still have these conflict errors:
how can I find out, what causes these conflicts.
2007-05-25T10:17:50 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/U431409/study_course/create_level:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) --
and finally:
------ 2007-05-25T10:19:01 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/C172676/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700)
Neither of those tracebacks look like they come out of the 'faster' session machinery itself; it uses an 'OOBTree' by default for storing the slices, not an 'IOBtree'. The primary consumer of 'IOBTree' is probably the catalog, where it is used to map RID -> values in the 'unindex' of 'FieldIndex', etc. The original sessioning machinery uses 'IOBTree', too: are you sure you are using the faster machnery? Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGVyLe+gerLs4ltQ4RAoGOAJ96Hl1UkY+mbeaik2uaNszWQgh4oACfcZe6 mDWlIPGApco0/yrlv1SxOYs= =hejZ -----END PGP SIGNATURE-----
Tres Seaver schrieb:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
------ 2007-05-25T10:19:01 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/C172676/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700)
Neither of those tracebacks look like they come out of the 'faster' session machinery itself; it uses an 'OOBTree' by default for storing the slices, not an 'IOBtree'. The primary consumer of 'IOBTree' is probably the catalog, where it is used to map RID -> values in the 'unindex' of 'FieldIndex', etc. The original sessioning machinery uses 'IOBTree', too: are you sure you are using the faster machnery?
Yes, but I am not sure, or better I don't know who is causing these errors. -- Gruß Joachim
Perry wrote:
Tres Seaver schrieb:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
------ 2007-05-25T10:19:01 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/C172676/study_course/create_level
Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700)
Neither of those tracebacks look like they come out of the 'faster' session machinery itself; it uses an 'OOBTree' by default for storing the slices, not an 'IOBtree'. The primary consumer of 'IOBTree' is probably the catalog, where it is used to map RID -> values in the 'unindex' of 'FieldIndex', etc. The original sessioning machinery uses 'IOBTree', too: are you sure you are using the faster machnery?
Yes, but I am not sure, or better I don't know who is causing these errors.
I wrote up some stuff on finding the path of an object http://plone.org/documentation/how-to/debug-zodb-bloat/ and http://www.zopelabs.com/cookbook/1114086617 The scripts need to be updated for recent ZODBs (change one import I think). Laurence
Perry wrote at 2007-5-25 13:16 +0200:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) ... ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700)
These log entries indicate a bug in ZODB's invalidation processing. The first entry tells us that the object was read at 9:14:16 and the modification conflicts with a write from 9:16:07. The second entry tells us that the object was read at 9:15:14 *BUT* at the time this transaction has started, the ZODB should already have known the modification from 9:16:07 and the object read at 9:15:14 should have been invalidated. The new transaction should not have seen any state older than 9:16:07 (as it begins after this time). In older ZODB versions, there has been a bug in "ZODB.Connection.Connection._setDB". It has forgotten to flush invalidations (which may lead to observations as the above). In our private Zope version, I have still a note like this: # DM 2005-08-22: always call '_flush_invalidations' as it does # more than cache handling only self._flush_invalidations() if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() # DM 2005-08-22: always call '_flush_invalidations' ## else: ## self._flush_invalidations() The note indicates that the bug was fixed at least at 2005-08-22 (though the handling was not completely right in case the cache was reset). Maybe, the bug you see now affects only mounted connections? -- Dieter
Hi Dieter, thanks for this hint. Dieter Maurer schrieb:
Perry wrote at 2007-5-25 13:16 +0200:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007)
In our private Zope version, I have still a note like this:
# DM 2005-08-22: always call '_flush_invalidations' as it does # more than cache handling only self._flush_invalidations() if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() # DM 2005-08-22: always call '_flush_invalidations' ## else: ## self._flush_invalidations()
The note indicates that the bug was fixed at least at 2005-08-22 (though the handling was not completely right in case the cache was reset). In ZODB.Connection.Connection.open I see:
if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() else: self._flush_invalidations() So self._flush_invalidations() is only called in the else-condition. In your patch it is always called. I try your version and report back. -- Gruß Joachim
Joachim Schmitz schrieb:
Hi Dieter,
thanks for this hint.
Dieter Maurer schrieb:
Perry wrote at 2007-5-25 13:16 +0200:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007)
In our private Zope version, I have still a note like this:
# DM 2005-08-22: always call '_flush_invalidations' as it does # more than cache handling only self._flush_invalidations() if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() # DM 2005-08-22: always call '_flush_invalidations' ## else: ## self._flush_invalidations()
The note indicates that the bug was fixed at least at 2005-08-22 (though the handling was not completely right in case the cache was reset). In ZODB.Connection.Connection.open I see:
if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() else: self._flush_invalidations()
So self._flush_invalidations() is only called in the else-condition. In your patch it is always called. I try your version and report back.
I patched the ZODB to always do the self._flush_invalidations(). But that didn't change anything, and after looking at the code it couldn't cause it was already always called. here again is the history of a conflict error for one user which finally fails: 2007-05-28T18:32:12 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/V659242/study_course/create_level: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefb352fd600 2007-05-28 17:31:12.465670, serial currently committed 0x036deefb9aa4d733 2007-05-28 17:31:36.244666) (34 conflicts (4 unresolved) since startup at Mon May 28 17:41:55 2007) 2007-05-28T18:32:44 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/V659242/study_course/create_level: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefb9aa4d733 2007-05-28 17:31:36.244666, serial currently committed 0x036deefc2e4ff122 2007-05-28 17:32:10.854439) (35 conflicts (4 unresolved) since startup at Mon May 28 17:41:55 2007) 2007-05-28T18:33:15 INFO Skins.create_level V659242 finished to create level 1002007-05-28T18:34:29 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/V659242/study_course/create_level: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefc2e4ff122 2007-05-28 17:32:10.854439, serial currently committed 0x036deefe18489244 2007-05-28 17:34:05.691441) (36 conflicts (4 unresolved) since startup at Mon May 28 17:41:55 2007) 2007-05-28T18:35:21 INFO Skins.create_level V659242 finished to create level 1002007-05-28T18:38:36 INFO ZPublisher.Conflict ConflictError at /VirtualHostBase/http/uniben.waeup.org:80/uniben/VirtualHostRoot/campus/students/V659242/study_course/create_level: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefe18489244 2007-05-28 17:34:05.691441, serial currently committed 0x036def009207e011 2007-05-28 17:36:34.225960) (42 conflicts (4 unresolved) since startup at Mon May 28 17:41:55 2007) ------ 2007-05-28T18:38:36 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/V659242/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefe18489244 2007-05-28 17:34:05.691441, serial currently committed 0x036def009207e011 2007-05-28 17:36:34.225960) ------ How can I find out, which objects are really involved in the conflict. -- Gruß Joachim
--On 28. Mai 2007 20:03:47 +0200 Joachim Schmitz <js@aixtraware.de> wrote:
Joachim Schmitz schrieb: ConflictError: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefe18489244 2007-05-28 17:34:05.691441, serial currently committed 0x036def009207e011 2007-05-28 17:36:34.225960) ------
How can I find out, which objects are really involved in the conflict.
from ZODB.utils import p64 print app._p_jar[p64(some_oid)] The oid is available from the traceback. If you are running ZEO it might be necessary to replace 'app' with the top-level (or some other object) of the related storage (might be tricky to figure out if you have multiple storages). -aj
--On 28. Mai 2007 21:12:13 +0200 Andreas Jung <lists@zopyx.com> wrote:
--On 28. Mai 2007 20:03:47 +0200 Joachim Schmitz <js@aixtraware.de> wrote:
Joachim Schmitz schrieb: ConflictError: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefe18489244 2007-05-28 17:34:05.691441, serial currently committed 0x036def009207e011 2007-05-28 17:36:34.225960) ------
How can I find out, which objects are really involved in the conflict.
from ZODB.utils import p64 print app._p_jar[p64(some_oid)]
The oid is available from the traceback. If you are running ZEO it might be necessary to replace 'app' with the top-level (or some other object) of the related storage (might be tricky to figure out if you have multiple storages).
Another trick that helped me lately to identify the reason for conflict errors was to implement the _p_resolveConflict() hook as method of the related class having the conflict. -aj
Andreas Jung schrieb:
--On 28. Mai 2007 21:12:13 +0200 Andreas Jung <lists@zopyx.com> wrote:
--On 28. Mai 2007 20:03:47 +0200 Joachim Schmitz <js@aixtraware.de> wrote:
Joachim Schmitz schrieb: ConflictError: database conflict error (oid 0x7fd771, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036deefe18489244 2007-05-28 17:34:05.691441, serial currently committed 0x036def009207e011 2007-05-28 17:36:34.225960) ------
How can I find out, which objects are really involved in the conflict.
from ZODB.utils import p64 print app._p_jar[p64(some_oid)]
The oid is available from the traceback. If you are running ZEO it might be necessary to replace 'app' with the top-level (or some other object) of the related storage (might be tricky to figure out if you have multiple storages).
Another trick that helped me lately to identify the reason for conflict errors was to implement the _p_resolveConflict() hook as method of the related class having the conflict.
How would I do that for the Class _IOBTree, which is in a c-module ? -- Gruß Joachim
Joachim Schmitz wrote at 2007-5-28 17:45 +0200:
In ZODB.Connection.Connection.open I see:
if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() else: self._flush_invalidations()
So self._flush_invalidations() is only called in the else-condition. In your patch it is always called. I try your version and report back.
As almost always "self._reset_counter == global_reset_counter" and "_resetCache" effectively flushes the cache, the change is *VERY* unlikely to affect what you see with respect to conflict errors. -- Dieter
Dieter Maurer wrote:
In our private Zope version, I have still a note like this:
# DM 2005-08-22: always call '_flush_invalidations' as it does # more than cache handling only self._flush_invalidations() if self._reset_counter != global_reset_counter: # New code is in place. Start a new cache. self._resetCache() # DM 2005-08-22: always call '_flush_invalidations' ## else: ## self._flush_invalidations()
The note indicates that the bug was fixed at least at 2005-08-22 (though the handling was not completely right in case the cache was reset).
Once again, it would be nice, now that you have access, if you could feed back your changes in areas like these rather than keeping them in your own private source tree :-( Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk
Chris Withers wrote at 2007-5-29 16:02 +0100:
... Once again, it would be nice, now that you have access, if you could feed back your changes in areas like these rather than keeping them in your own private source tree :-(
I would be busy for about 1 to 2 weeks -- and I do not have that time now. Moreover, people may not like what I would change -- and an intense discussion, maybe even struggle may be unravelled. So, you will still here from time to time a reference to our private copy of Zope. -- Dieter
Dieter Maurer schrieb:
Perry wrote at 2007-5-25 13:16 +0200:
database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2a44454dee 2007-05-25 09:14:16.000950, serial currently committed 0x036ddc2c21950377 2007-05-25 09:16:07.870801) (80 conflicts (10 unresolved) since startup at Fri May 25 05:19:08 2007) ... ConflictError: database conflict error (oid 0x7905e6, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036ddc2b3e989fdd 2007-05-25 09:15:14.670982, serial currently committed 0x036ddc2dd48f4e33 2007-05-25 09:17:49.818700)
These log entries indicate a bug in ZODB's invalidation processing.
The first entry tells us that the object was read at 9:14:16 and the modification conflicts with a write from 9:16:07.
The second entry tells us that the object was read at 9:15:14 *BUT* at the time this transaction has started, the ZODB should already have known the modification from 9:16:07 and the object read at 9:15:14 should have been invalidated. The new transaction should not have seen any state older than 9:16:07 (as it begins after this time).
I could reproduce the conflict error on my local machine not using ZEO. I invoked the longrunning process "create_level" for two users after a zope-restart. here is the log: 2007-05-31 09:44:24 INFO Zope Ready to handle requests 2007-05-31 09:44:39 INFO Skins.create_level A923157 started to create level 200 2007-05-31 09:44:41 INFO Skins.create_level Y617041 started to create level 400 the next two entries are printed before the redirect/commit 2007-05-31 09:45:01 INFO Skins.create_level Y617041 finished to create level 400 2007-05-31 09:45:06 INFO Skins.create_level A923157 finished to create level 200 Now the conflict error, look at the transaction start-time, this is before the restart of zope !! 2007-05-31 09:45:25 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x3360e3, class BTrees._OIBTree.OIBucket, serial this txn started with 0x036dfd7c73dfc1dd 2007-05-31 07:24:27.157981, serial currently committed 0x036dfd9131112455 2007-05-31 07:45:11.500069) (1 conflicts (0 unresolved) since startup at Thu May 31 09:44:24 2007) now this is retried for A923157 2007-05-31 09:45:26 INFO Skins.create_level A923157 started to create level 200 2007-05-31 09:45:45 INFO Skins.create_level A923157 finished to create level 200 -- Gruß Joachim
Joachim Schmitz schrieb:
I could reproduce the conflict error on my local machine not using ZEO.
I invoked the longrunning process "create_level" for two users after a zope-restart. here is the log:
2007-05-31 09:44:24 INFO Zope Ready to handle requests
2007-05-31 09:44:39 INFO Skins.create_level A923157 started to create level 200 2007-05-31 09:44:41 INFO Skins.create_level Y617041 started to create level 400 the next two entries are printed before the redirect/commit 2007-05-31 09:45:01 INFO Skins.create_level Y617041 finished to create level 400 2007-05-31 09:45:06 INFO Skins.create_level A923157 finished to create level 200 Now the conflict error, look at the transaction start-time, this is before the restart of zope !!
2007-05-31 09:45:25 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x3360e3, class BTrees._OIBTree.OIBucket, serial this txn started with 0x036dfd7c73dfc1dd 2007-05-31 07:24:27.157981, serial currently committed 0x036dfd9131112455 2007-05-31 07:45:11.500069) (1 conflicts (0 unresolved) since startup at Thu May 31 09:44:24 2007)
now this is retried for A923157
2007-05-31 09:45:26 INFO Skins.create_level A923157 started to create level 200 2007-05-31 09:45:45 INFO Skins.create_level A923157 finished to create level 200
I deleted the created objects and repeated the test: 2007-05-31 12:46:12 ERROR Zope.ZCatalog uncatalogObject unsuccessfully attempted to uncatalog an object with a uid of /uniben/campus/students/A923157/study_course/200/ZOO213. 2007-05-31 12:47:05 INFO Skins.create_level Y617041 started to create level 400 2007-05-31 12:47:14 INFO Skins.create_level A923157 started to create level 200 2007-05-31 12:47:25 INFO Skins.create_level Y617041 finished to create level 400 2007-05-31 12:47:40 INFO Skins.create_level A923157 finished to create level 200 2007-05-31 12:47:58 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x3647b0, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036dfe463486d955 2007-05-31 10:46:12.310958, serial currently committed 0x036dfe479a5725cc 2007-05-31 10:47:36.173536) (3 conflicts (0 unresolved) since startup at Thu May 31 09:44:24 2007) again the txn starttime is that of an older transaction, and it is the time of the uncatalog entry. If I invoke the create_level only for one student, no conflict-error occurs. -- Gruß Joachim
I deleted the created objects and repeated the test:
2007-05-31 12:46:12 ERROR Zope.ZCatalog uncatalogObject unsuccessfully attempted to uncatalog an object with a uid of /uniben/campus/students/A923157/study_course/200/ZOO213. 2007-05-31 12:47:05 INFO Skins.create_level Y617041 started to create level 400 2007-05-31 12:47:14 INFO Skins.create_level A923157 started to create level 200 2007-05-31 12:47:25 INFO Skins.create_level Y617041 finished to create level 400 2007-05-31 12:47:40 INFO Skins.create_level A923157 finished to create level 200 2007-05-31 12:47:58 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x3647b0, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036dfe463486d955 2007-05-31 10:46:12.310958, serial currently committed 0x036dfe479a5725cc 2007-05-31 10:47:36.173536) (3 conflicts (0 unresolved) since startup at Thu May 31 09:44:24 2007)
again the txn starttime is that of an older transaction, and it is the time of the uncatalog entry.
If I invoke the create_level only for one student, no conflict-error occurs.
I've checked my logs for conflict errors with session machinery. I also had times earlier than zope startup: http://mail.zope.org/pipermail/zope-dev/2007-April/029244.html I don't know why... Maybe your problem is simply that 'create_level' does something with Catalog (as Tres Seaver suggested). If so, then if one transaction changes it then second transaction raises conflict. With sessions I had problems with OOBTree not IOBTree. -- Maciej Wisniowski
Hi, I was able to locate the places in the Zope-sources where the conflict error is triggered. On my local system it's in ZODB.FileStorage in the store-method there is if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data) in the tryToResolveConflict method of ZODB.ConnflictResolution there is: committed = state(self, oid, committedSerial, prfactory, committedData) print "resolve", resolve resolved = resolve(old, committed, newstate) I found that the resolve-function raises an ConflictError exception, so I put an print there to find out which resolve function. Here is the output: resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb28fff6c>> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c80c> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c614> resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb2a9146c>> resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1b81224> The last resolve raises an exeption (Pdb) p sys.exc_info() (<class ZODB.POSException.BTreesConflictError at 0xb78df0bc>, BTreesConflictError(-1, 47, 47, 6), <traceback object at 0xb1c34dec>) How can I invest this further, especially how can I get information about the actual object,which is causing the conflict. -- Gruß Joachim
resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb28fff6c>> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c80c> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c614> resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb2a9146c>> resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1b81224>
The last resolve raises an exeption
(Pdb) p sys.exc_info() (<class ZODB.POSException.BTreesConflictError at 0xb78df0bc>, BTreesConflictError(-1, 47, 47, 6), <traceback object at 0xb1c34dec>)
Length, IOBucket and such things seems to me to be related to session machinery. What timeout and resolution times you have now? Also try if there are differences when you try to call your methods just after zope restart and after few different calls to get session objects created.
How can I invest this further, especially how can I get information about the actual object,which is causing the conflict. http://www.zopelabs.com/cookbook/1054240694 Maybe this will help. Take a look at comments on this page.
-- Maciej Wisniowski
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Maciej Wisniowski wrote:
resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb28fff6c>> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb1b81224> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c80c> resolve <built-in method _p_resolveConflict of BTrees._OIBTree.OIBucket object at 0xb260c614> resolve <bound method Length._p_resolveConflict of <BTrees.Length.Length object at 0xb2a9146c>> resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1b81224>
The last resolve raises an exeption
(Pdb) p sys.exc_info() (<class ZODB.POSException.BTreesConflictError at 0xb78df0bc>, BTreesConflictError(-1, 47, 47, 6), <traceback object at 0xb1c34dec>) Length, IOBucket and such things seems to me to be related to session machinery. What timeout and resolution times you have now? Also try if there are differences when you try to call your methods just after zope restart and after few different calls to get session objects created.
Not if the sessions being used are from 'faster' -- it doesn't use IOBTree. The major "application" use of that module is in the catalog. Try dumping out the contents of the bucket: for k, v in bucket.items(): print k, type(v) Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGXzzr+gerLs4ltQ4RAvF8AKColGLB4jh/f5P0rffXGY6+USp31gCdHdBD ly+PHJ28HDBCTKrTSEJ2OZA= =QOWx -----END PGP SIGNATURE-----
Tres Seaver schrieb:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Not if the sessions being used are from 'faster' -- it doesn't use IOBTree. The major "application" use of that module is in the catalog.
you correct see below:
Try dumping out the contents of the bucket:
for k, v in bucket.items(): print k, type(v)
resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1ab82b4> print root._p_jar[p64(0xb1ab82b4)] *** POSKeyError: <ZODB.POSException.POSKeyError instance at 0xa8f9e6cc> with the recepies here http://www.zopelabs.com/cookbook/1114086617 I was able to get the information about the oid, which is passed to tryToResolveConflict, here is the result <BTrees._IOBTree.IOBTree object at 0xb562fadc> <DateIndex at created> <Products.ZCatalog.Catalog.Catalog object at 0xb12d622c> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb2739224>} What does this tell us ? -- Gruß Joachim
one very important finding: tryToResolveConflict fails in the resolve function resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1ab82b4> by raising an exception, when I call it again from the debugger I get. (Pdb) resolved = resolve(old, committed, newstate) *** BTreesConflictError: BTrees conflict error at -1/47/47: Conflicting inserts So that is the real error. -- Gruß Joachim
some more findings: 1. The conflict error really happens on the Portalcatalog 2. It is a BTreesConflictError: BTrees conflict error at -1/47/47: Conflicting inserts which disguised as ConflictError, through the various try: excepts: 3. It happens on DateIndexes like "created" and "modified". 4. I put for a test: try: resolved = resolve(old, committed, newstate) except: return "invalidated" into tryToResolveConflict and into the store-method of FileStorage: if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data) if rdata is None: raise POSException.ConflictError(oid=oid, serials=(cached_tid, serial), data=data) elif rdata == "invalidated": #new for test old = False # pass # With these hacks I get rid of the conflictErrors. But when I delete the created Items I get: 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379718 from index created but couldn't. This should not happen. 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379838 from index Date but couldn't. This should not happen. 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379719 from index modified but couldn't. This should not happen. So obviously I just fix the symptom with this hack. I think the real cause: lies in these lines: if old: cached_tid = self._get_cached_tid(oid) if cached_tid is None: h = self._read_data_header(old, oid) if h.version: if h.version != version: raise VersionLockError(oid, h.version) pnv = h.pnv cached_tid = h.tid if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data) Which is also supported by the fact, that on our live system which is running on 4 zeo-clients we get this traceback: 2007-06-01T12:38:59 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/F541700/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x8fe833, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036e0418ddcccf55 2007-06-01 11:36:51.984384, serial currently committed 0x036e041a3a33e311 2007-06-01 11:38:13.641254) Any suggestion for a temporary fix would be very welcome, since we get about 6000 conflict errors per day now about 15 % unresolved, and they are really killing our portal. -- Gruß Joachim
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Joachim Schmitz wrote:
some more findings:
1. The conflict error really happens on the Portalcatalog 2. It is a BTreesConflictError: BTrees conflict error at -1/47/47: Conflicting inserts which disguised as ConflictError, through the various try: excepts:
3. It happens on DateIndexes like "created" and "modified".
4. I put for a test: try: resolved = resolve(old, committed, newstate) except: return "invalidated"
into tryToResolveConflict
and into the store-method of FileStorage:
if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data) if rdata is None: raise POSException.ConflictError(oid=oid, serials=(cached_tid, serial), data=data) elif rdata == "invalidated": #new for test old = False # pass #
With these hacks I get rid of the conflictErrors. But when I delete the created Items I get: 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379718 from index created but couldn't. This should not happen. 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379838 from index Date but couldn't. This should not happen. 2007-06-01 13:20:33 ERROR Zope.UnIndex DateIndex: unindex_object tried to retrieve set 1075379719 from index modified but couldn't. This should not happen.
So obviously I just fix the symptom with this hack. I think the real cause:
lies in these lines:
if old: cached_tid = self._get_cached_tid(oid) if cached_tid is None: h = self._read_data_header(old, oid) if h.version: if h.version != version: raise VersionLockError(oid, h.version) pnv = h.pnv cached_tid = h.tid
if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data)
Which is also supported by the fact, that on our live system which is running on 4 zeo-clients we get this traceback:
2007-06-01T12:38:59 ERROR Zope.SiteErrorLog http://uniben.waeup.org/campus/students/F541700/study_course/create_level Traceback (innermost last): Module Zope2.App.startup, line 173, in zpublisher_exception_hook Module ZPublisher.Publish, line 121, in publish Module Zope2.App.startup, line 240, in commit Module transaction._manager, line 96, in commit Module Products.CPSCompat.PatchZODBTransaction, line 175, in commit Module transaction._transaction, line 436, in _commitResources Module ZODB.Connection, line 665, in tpc_vote Module ZEO.ClientStorage, line 893, in tpc_vote Module ZEO.ClientStorage, line 877, in _check_serials ConflictError: database conflict error (oid 0x8fe833, class BTrees._IOBTree.IOBucket, serial this txn started with 0x036e0418ddcccf55 2007-06-01 11:36:51.984384, serial currently committed 0x036e041a3a33e311 2007-06-01 11:38:13.641254)
Any suggestion for a temporary fix would be very welcome, since we get about 6000 conflict errors per day now about 15 % unresolved, and they are really killing our portal.
A workaround might be to replace the DateIndexes for 'created' and 'modified' with FieldIndexes: you will see a big jump in the number of keys in the index, but (perhaps) a reduction in conflicts (altheough there will be more bucket splits, which can also cause conflicts). A longer term solution might be to come up with a derived index type which used non-persistent objects (rather than the IITreeSet used by UnIndex) for the set of RIDs stored under each 'minute': you could then inspect the state and do more aggressive conflict resolution than the stock implementation allows (see my other post). Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGYB4w+gerLs4ltQ4RAhsLAJ9/TR4unlzPMQBY7gfpT6WmQZovywCfQrAF EnkttfiHM7gk1ENrm+ineA4= =oJqE -----END PGP SIGNATURE-----
Any suggestion for a temporary fix would be very welcome, since we get about 6000 conflict errors per day now about 15 % unresolved, and they are really killing our portal.
A workaround might be to replace the DateIndexes for 'created' and 'modified' with FieldIndexes: you will see a big jump in the number of keys in the index, but (perhaps) a reduction in conflicts (altheough there will be more bucket splits, which can also cause conflicts).
Unfortunately that does not work the FieldIndex also gives an conflict-error <FieldIndex at Date> <Products.ZCatalog.Catalog.Catalog object at 0xb250a6ec> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb242989c>} 2007-06-01 20:23:41 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x36c429, class BTrees._OOBTree.OOBTree, serial this txn started with 0x036e0590d58661ee 2007-06-01 17:52:50.044906, serial currently committed 0x036e059346ef95dd 2007-06-01 17:55:16.625597) (1 conflicts (0 unresolved) since startup at Fri Jun 1 19:54:43 2007)
A longer term solution might be to come up with a derived index type which used non-persistent objects (rather than the IITreeSet used by UnIndex) for the set of RIDs stored under each 'minute': you could then inspect the state and do more aggressive conflict resolution than the stock implementation allows (see my other post).
any other shortterm suggestions. -- Gruß Joachim
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Joachim Schmitz wrote:
Any suggestion for a temporary fix would be very welcome, since we get about 6000 conflict errors per day now about 15 % unresolved, and they are really killing our portal. A workaround might be to replace the DateIndexes for 'created' and 'modified' with FieldIndexes: you will see a big jump in the number of keys in the index, but (perhaps) a reduction in conflicts (altheough there will be more bucket splits, which can also cause conflicts).
Unfortunately that does not work the FieldIndex also gives an conflict-error <FieldIndex at Date> <Products.ZCatalog.Catalog.Catalog object at 0xb250a6ec> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb242989c>} 2007-06-01 20:23:41 INFO ZPublisher.Conflict ConflictError at /uniben/campus/students/A923157/study_course/create_level: database conflict error (oid 0x36c429, class BTrees._OOBTree.OOBTree, serial this txn started with 0x036e0590d58661ee 2007-06-01 17:52:50.044906, serial currently committed 0x036e059346ef95dd 2007-06-01 17:55:16.625597) (1 conflicts (0 unresolved) since startup at Fri Jun 1 19:54:43 2007)
A longer term solution might be to come up with a derived index type which used non-persistent objects (rather than the IITreeSet used by UnIndex) for the set of RIDs stored under each 'minute': you could then inspect the state and do more aggressive conflict resolution than the stock implementation allows (see my other post).
any other shortterm suggestions.
QueueCatalog? Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGYGZU+gerLs4ltQ4RAk4BAJ46DKm1vLlygIqee1OxUjSPYF40pwCfSLvy mS+9UyTtv0OuNWuotzqk5Tg= =Fevy -----END PGP SIGNATURE-----
Joachim Schmitz wrote at 2007-6-1 20:26 +0200:
....
A longer term solution might be to come up with a derived index type which used non-persistent objects (rather than the IITreeSet used by UnIndex) for the set of RIDs stored under each 'minute': you could then inspect the state and do more aggressive conflict resolution than the stock implementation allows (see my other post).
any other shortterm suggestions.
Not sure that it can really help you in this case: but "ManagableIndex" solves several problems with Zope's standard indexes. The available indexes do not have a resolution below seconds (thus, you may still see "ConflictError"s) but it would be difficult to create an index that follows Tres suggestion. -- Dieter
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Joachim Schmitz wrote:
Tres Seaver schrieb:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Not if the sessions being used are from 'faster' -- it doesn't use IOBTree. The major "application" use of that module is in the catalog.
you correct see below:
Try dumping out the contents of the bucket:
for k, v in bucket.items(): print k, type(v)
resolve <built-in method _p_resolveConflict of BTrees._IOBTree.IOBucket object at 0xb1ab82b4>
print root._p_jar[p64(0xb1ab82b4)] *** POSKeyError: <ZODB.POSException.POSKeyError instance at 0xa8f9e6cc>
with the recepies here http://www.zopelabs.com/cookbook/1114086617 I was able to get the information about the oid, which is passed to tryToResolveConflict, here is the result
<BTrees._IOBTree.IOBTree object at 0xb562fadc> <DateIndex at created> <Products.ZCatalog.Catalog.Catalog object at 0xb12d622c> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb2739224>}
What does this tell us ?
That is a "real" conflict: both transactions have inserted values into the 'created' date index's '_index' under the same key, which can't be resolved. Retrying the transaction is the only choice here. Because DateIndexes convert the indexed value to an integer with precision of one minute, a date index on 'created' is fairly likely to generate such conflicts when two parties both create content at the same time. Ideally, one would examine the two values being inserted, note that they were both IITreeSet instances containing one int apiece, and exploit our knowledge of the application semantics to merge them, removing the conflict; however, *because* they are IITreeSets, and therefore separate persistent objects, their state is not available to the bucket's '_p_resolveConflict', which must therefore lose. Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGYBDQ+gerLs4ltQ4RAoRNAKCb86Bjhp5fuk7bp9OV2IMUXDKm7ACeO/aH hVfzx/U0rXsM3iNT2fOl2As= =egtx -----END PGP SIGNATURE-----
Tres Seaver schrieb:
<BTrees._IOBTree.IOBTree object at 0xb562fadc> <DateIndex at created> <Products.ZCatalog.Catalog.Catalog object at 0xb12d622c> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb2739224>}
What does this tell us ?
That is a "real" conflict: both transactions have inserted values into the 'created' date index's '_index' under the same key, which can't be resolved. Retrying the transaction is the only choice here.
Because DateIndexes convert the indexed value to an integer with precision of one minute, really one minute or do you mean second.
a date index on 'created' is fairly likely to
generate such conflicts when two parties both create content at the same time. But then I wonder how a CMF site could ever work, this error shows up already on my lokal system when to users add something. On our live system it is killing our portal ? I would consider this a bug.
Ideally, one would examine the two values being inserted, note that they were both IITreeSet instances containing one int apiece, and exploit our knowledge of the application semantics to merge them, removing the conflict; however, *because* they are IITreeSets, and therefore separate persistent objects, their state is not available to the bucket's '_p_resolveConflict', which must therefore lose.
-- Gruß Joachim
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Joachim Schmitz wrote:
Tres Seaver schrieb:
<BTrees._IOBTree.IOBTree object at 0xb562fadc> <DateIndex at created> <Products.ZCatalog.Catalog.Catalog object at 0xb12d622c> <CatalogTool at portal_catalog> <CPSDefaultSite at uniben> <Application at > {'Application': <Application at >, 'ZGlobals': <BTrees._OOBTree.OOBTree object at 0xb2739224>}
What does this tell us ? That is a "real" conflict: both transactions have inserted values into the 'created' date index's '_index' under the same key, which can't be resolved. Retrying the transaction is the only choice here.
Because DateIndexes convert the indexed value to an integer with precision of one minute, really one minute or do you mean second.
Yes, really one minute.
a date index on 'created' is fairly likely to
generate such conflicts when two parties both create content at the same time. But then I wonder how a CMF site could ever work,
You only see conflicts on this index when two people try to insert content at the same time (i.e., they both start from the same "base" transaction ID).
this error shows up already on my lokal system when to users add something. On our live system it is killing our portal ? I would consider this a bug.
Perhaps the QueueCatalog product would help you: that would allow you to defer updates to the "conflict-prone" indexes (created, modified, plus any {ZC,}TextIndexes) for handling by a separate batch process: http://svn.zope.org/Products.QueueCatalog It looks as though you may need the trunk version for compatibility with Zope >= 2.9. Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGYCDR+gerLs4ltQ4RAuI8AJ9eRg+ZIdh3Cdqog3adXQuSIdByHgCeJN0M 8Qb5I8saP9W0eIy+5/OlAmg= =e5qN -----END PGP SIGNATURE-----
On 5/31/07, Joachim Schmitz <js@aixtraware.de> wrote:
Hi,
I was able to locate the places in the Zope-sources where the conflict error is triggered. On my local system it's in
ZODB.FileStorage in the store-method there is
if serial != cached_tid: rdata = self.tryToResolveConflict(oid, cached_tid,serial, data)
in the tryToResolveConflict method of ZODB.ConnflictResolution there is:
committed = state(self, oid, committedSerial, prfactory, committedData) print "resolve", resolve resolved = resolve(old, committed, newstate)
I'm not really sure, but have a look here: http://mail.zope.org/pipermail/zope-dev/2006-June/027573.html http://mail.zope.org/pipermail/zope-dev/2006-June/027583.html Maybe that helps. -- Markus
Joachim Schmitz wrote at 2007-5-31 12:07 +0200:
... 2007-05-31 09:45:06 INFO Skins.create_level A923157 finished to create level 200 Now the conflict error, look at the transaction start-time, this is before the restart of zope !!
You are probably tricked out here: the serials are in fact UTC timestamps. I am not sure but it may well be that the times shown for the serials are UTC (GMT +0) and not local times. -- Dieter
Dieter Maurer schrieb:
Joachim Schmitz wrote at 2007-5-31 12:07 +0200:
... 2007-05-31 09:45:06 INFO Skins.create_level A923157 finished to create level 200 Now the conflict error, look at the transaction start-time, this is before the restart of zope !!
You are probably tricked out here: the serials are in fact UTC timestamps. I am not sure but it may well be that the times shown for the serials are UTC (GMT +0) and not local times.
I added 2 hours to the txn times and only looked at minutes. so the observation is still true. -- Gruß Joachim
participants (10)
-
Andreas Jung -
Chris McDonough -
Chris Withers -
Dieter Maurer -
Joachim Schmitz -
Laurence Rowe -
M. Krainer -
Maciej Wisniowski -
Perry -
Tres Seaver