[ZODB-Dev] Re: [Bug] ZODB invalidation processing

2007-05-31 Thread Joachim Schmitz

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

___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev


[ZODB-Dev] Re: [Zope-dev] Re: [Bug] ZODB invalidation processing

2007-05-31 Thread Joachim Schmitz

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

___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev


Re: [ZODB-Dev] Re: [Bug] ZODB invalidation processing

2007-05-31 Thread Dieter Maurer
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
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev


Re: [ZODB-Dev] Re: [Bug] ZODB invalidation processing

2007-05-31 Thread Perry

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

___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev


[ZODB-Dev] Re: [Zope-dev] Re: [Bug] ZODB invalidation processing

2007-05-31 Thread Joachim Schmitz

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

___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev


[ZODB-Dev] Todo: Zope support for Slots and Decorators?

2007-05-31 Thread Chris Spencer

A couple questions. Does ZODB support classes using __slots__? Also,
are there any problems with using decorators with ZODB? For instance,
a simple memoization decorator like http://paste.plone.org/5416
appears to work in simple tests, but are there any potential issues I
should be aware of?

Chris
___
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/

ZODB-Dev mailing list  -  ZODB-Dev@zope.org
http://mail.zope.org/mailman/listinfo/zodb-dev