[ZODB-Dev] ReadConflictErrors with ZODB3.10.1 and Relstorage 1.4.1

[Jürgen Herrmann]

 i everybody!

 About a week ago i migrated our FileStorages to Relstorage instances.
 We have 5 databases, 4 of them mounted via ZodbMountPoints in a plain
 zope 2.13 installation.

 Since the migration i experience sporadic ReadConflictErrors (they
 occur about 1-4 hours after restarting the zope daemon).

 These ReadConflictErrors are not resolved by the ZPlublisher retries,
 instead all of them finally hit the SiteErrorLog after 3 retries.

 Here's a traceback of such an exception (the final one):
 2011-01-26T12:55:59 ERROR Zope.SiteErrorLog 1296042959.440.268001912558 
 https://new.xlhost.de:456/InstanceEditor/index_html
 Traceback (innermost last):
   Module Zope2.App.startup, line 197, in __call__
   Module ZPublisher.Publish, line 134, in publish
   Module Zope2.App.startup, line 301, in commit
   Module transaction._manager, line 95, in commit
   Module transaction._transaction, line 329, in commit
   Module transaction._transaction, line 443, in _commitResources
   Module ZODB.Connection, line 599, in commit
 ReadConflictError: database read conflict error (oid 0xfd19b5, serial 
 this
 txn started with 0x038bd509f31cdf33 2011-01-25 10:49:56.979558, serial
 currently co mmitted 0x038bdad75eed2344 2011-01-26 11:35:22.248356)

 Please note that actually with plain ZODB 3.10.1 it's Connection.py
 line 570, but i added some logging code there for debugging purposes.

 It took me ages to find the cause for that problem and i think i found
 it by now, but not what causes this. The cause for the 
 ReadConflictErrors
 is that the connection object has the oid 0xfd19b5 in it's _readCurrent
 dict and never throws it out. the concerned transaction above i'm 
 pretty
 sure never read that object with oid 0xfd19b5, so either it's wrongly
 added to _readCurrent or (much more likely imho) it never gets removed
 from _readCurrent though it should.

 if i execute the following code in the debugger, the readconflicts
 concerning that oid are gone (please note that this happens in a new
 request, so i'm operating on the reused Connection object. _readCurrent
 is obviously reused and not cleared at transaction boundaries, is that
 expected?):

 from ZODB.utils import p64, u64
 del object._p_jar._readCurrent[p64(0xfd19b5)]
 import transaction; transaction.commit()

 I'm sorry I cannot give you a minimal example to reproduce this error.
 That's also what makes it so difficult to debug, it's not reproduceable
 or at least i don't know how to provoke those errors yet.

 Does anybody have a clue what's going on here, any pointers in which
 direction to look next?`

 Best regards,
 Jürgen
-- 
>> XLhost.de ® - Webspace von supersmall bis eXtra Large <<

 XLhost.de GmbH
 Jürgen Herrmann, Geschäftsführer
 Boelckestrasse 21, 93051 Regensburg, Germany

 Geschäftsführer: Jürgen Herrmann
 Registriert unter: HRB9918
 Umsatzsteuer-Identifikationsnummer: DE245931218

 Fon:  +49 (0)800 XLHOSTDE [0800 95467833]
 Fax:  +49 (0)800 95467830
 Web:  http://www.XLhost.de