Re: [ZODB-Dev] Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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
On 5/31/07, Joachim Schmitz <[EMAIL PROTECTED]> 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 ___ 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
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
{'Application': , 'ZGlobals': 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
___
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
-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 [EMAIL PROTECTED] 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- ___ 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: [ZODB-Dev] Re: [Zope-dev] Re: [Bug] ZODB invalidation processing
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 ___ 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
one very important finding: tryToResolveConflict fails in the resolve function resolve 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 ___ 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 object at 0xb28fff6c>> > resolve object at 0xb1b81224> > resolve object at 0xb1b81224> > resolve object at 0xb260c80c> > resolve object at 0xb260c614> > resolve object at 0xb2a9146c>> > resolve object at 0xb1b81224> > > The last resolve raises an exeption > > (Pdb) p sys.exc_info() > (, > BTreesConflictError(-1, 47, 47, 6), ) 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 )
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 object at 0xb28fff6c>> resolve object at 0xb1b81224> resolve object at 0xb1b81224> resolve object at 0xb260c80c> resolve object at 0xb260c614> resolve object at 0xb2a9146c>> resolve object at 0xb1b81224> The last resolve raises an exeption (Pdb) p sys.exc_info() (, BTreesConflictError(-1, 47, 47, 6), ) 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
> > 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 )
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 )
