Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
[Zope-dev] Zope Tests: 5 OK
Summary of messages to the zope-tests list. Period Wed May 30 12:00:00 2007 UTC to Thu May 31 12:00:00 2007 UTC. There were 5 messages: 5 from Zope Unit Tests. Tests passed OK --- Subject: OK : Zope-2.7 Python-2.3.6 : Linux From: Zope Unit Tests Date: Wed May 30 20:52:11 EDT 2007 URL: http://mail.zope.org/pipermail/zope-tests/2007-May/007809.html Subject: OK : Zope-2.8 Python-2.3.6 : Linux From: Zope Unit Tests Date: Wed May 30 20:53:42 EDT 2007 URL: http://mail.zope.org/pipermail/zope-tests/2007-May/007810.html Subject: OK : Zope-2.9 Python-2.4.4 : Linux From: Zope Unit Tests Date: Wed May 30 20:55:13 EDT 2007 URL: http://mail.zope.org/pipermail/zope-tests/2007-May/007811.html Subject: OK : Zope-2.10 Python-2.4.4 : Linux From: Zope Unit Tests Date: Wed May 30 20:56:46 EDT 2007 URL: http://mail.zope.org/pipermail/zope-tests/2007-May/007812.html Subject: OK : Zope-trunk Python-2.4.4 : Linux From: Zope Unit Tests Date: Wed May 30 20:58:17 EDT 2007 URL: http://mail.zope.org/pipermail/zope-tests/2007-May/007813.html ___ 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 )
[Zope-dev] Re: [ZODB-Dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
[Zope-dev] Re: [ZODB-Dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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 )
