[Checkins] SVN: relstorage/trunk/ - Fixed a subtle bug in the cache code that could lead to an
Shane Hathaway
shane at hathawaymix.org
Thu Jul 29 01:32:17 EDT 2010
Log message for revision 115183:
- Fixed a subtle bug in the cache code that could lead to an
AssertionError indicating a cache inconsistency. The inconsistency
was caused by after_poll(), which was ignoring the randomness of
the order of the list of recent changes, leading it to sometimes
put the wrong transfer ID in the "delta_after" dicts. Also expanded
the AssertionError with debugging info, since cache inconsistency
can still be caused by database misconfiguration and mismatched
client versions.
- Oracle: updated the migration notes. The relstorage_util package
is not needed after all.
Changed:
U relstorage/trunk/CHANGES.txt
U relstorage/trunk/notes/migrate-to-1.4.txt
U relstorage/trunk/relstorage/adapters/schema.py
U relstorage/trunk/relstorage/cache.py
U relstorage/trunk/relstorage/tests/test_cache.py
U relstorage/trunk/setup.py
-=-
Modified: relstorage/trunk/CHANGES.txt
===================================================================
--- relstorage/trunk/CHANGES.txt 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/CHANGES.txt 2010-07-29 05:32:16 UTC (rev 115183)
@@ -1,3 +1,19 @@
+
+1.4.0c2 (2010-07-28)
+--------------------
+
+- Fixed a subtle bug in the cache code that could lead to an
+ AssertionError indicating a cache inconsistency. The inconsistency
+ was caused by after_poll(), which was ignoring the randomness of
+ the order of the list of recent changes, leading it to sometimes
+ put the wrong transfer ID in the "delta_after" dicts. Also expanded
+ the AssertionError with debugging info, since cache inconsistency
+ can still be caused by database misconfiguration and mismatched
+ client versions.
+
+- Oracle: updated the migration notes. The relstorage_util package
+ is not needed after all.
+
1.4.0c1 (2010-06-19)
--------------------
Modified: relstorage/trunk/notes/migrate-to-1.4.txt
===================================================================
--- relstorage/trunk/notes/migrate-to-1.4.txt 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/notes/migrate-to-1.4.txt 2010-07-29 05:32:16 UTC (rev 115183)
@@ -6,40 +6,12 @@
RelStorage version 1.1.2 by following the directions in "migrate-to-1.1.2.txt".
Only Oracle needs a change for this release. The Oracle adapter
-now requires the installation of a PL/SQL package with ``SYS`` privileges.
+now requires the EXECUTE permission on the DBMS_LOCK package.
+In the example below, "zodb" is the name of the account::
-Using Oracle 10g XE, you can start a ``SYS`` session with the following
-shell commands::
+ GRANT EXECUTE ON DBMS_LOCK TO zodb;
- $ su - oracle
- $ sqlplus / as sysdba
+Also, the Oracle adapter in RelStorage no longer uses the commit_lock
+table, so you can drop it. It contains no data.
-The PL/SQL package below provides limited access to the DBMS_LOCK
-package so that RelStorage can acquire user locks. Using ``sqlplus``
-with ``SYS`` privileges, execute the following::
-
- CREATE OR REPLACE PACKAGE relstorage_util AS
- FUNCTION request_lock(id IN NUMBER, timeout IN NUMBER)
- RETURN NUMBER;
- END relstorage_util;
- /
-
- CREATE OR REPLACE PACKAGE BODY relstorage_util AS
- FUNCTION request_lock(id IN NUMBER, timeout IN NUMBER)
- RETURN NUMBER IS
- BEGIN
- RETURN DBMS_LOCK.REQUEST(
- id => id,
- lockmode => DBMS_LOCK.X_MODE,
- timeout => timeout,
- release_on_commit => TRUE);
- END request_lock;
- END relstorage_util;
- /
-
-Also with ``SYS`` privileges, grant the execute permission on the
-relstorage_util package to the Oracle account that holds the
-database. In the example below, "zodb" is the name of the account::
-
- GRANT EXECUTE ON relstorage_util TO zodb;
-
+ DROP TABLE commit_lock;
Modified: relstorage/trunk/relstorage/adapters/schema.py
===================================================================
--- relstorage/trunk/relstorage/adapters/schema.py 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/relstorage/adapters/schema.py 2010-07-29 05:32:16 UTC (rev 115183)
@@ -23,14 +23,12 @@
history_preserving_schema = """
-# commit_lock: Held during commit. Another kind of lock is used for MySQL.
+# commit_lock: Held during commit. Another kind of lock is used for MySQL
+# and Oracle.
postgresql:
CREATE TABLE commit_lock ();
- oracle:
- CREATE TABLE commit_lock (dummy CHAR);
-
# pack_lock: Held during pack. Another kind of lock is used for MySQL.
# Another kind of lock is used for PostgreSQL >= 8.2.
@@ -399,14 +397,12 @@
history_free_schema = """
-# commit_lock: Held during commit. Another kind of lock is used for MySQL.
+# commit_lock: Held during commit. Another kind of lock is used for MySQL
+# and Oracle.
postgresql:
CREATE TABLE commit_lock ();
- oracle:
- CREATE TABLE commit_lock (dummy CHAR);
-
# pack_lock: Held during pack. Another kind of lock is used for MySQL.
# Another kind of lock is used for PostgreSQL >= 8.2.
Modified: relstorage/trunk/relstorage/cache.py
===================================================================
--- relstorage/trunk/relstorage/cache.py 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/relstorage/cache.py 2010-07-29 05:32:16 UTC (rev 115183)
@@ -159,7 +159,53 @@
# Cache miss.
state, actual_tid_int = self.adapter.mover.load_current(
cursor, oid_int)
- assert actual_tid_int == tid_int
+ if actual_tid_int != tid_int:
+ # Uh-oh, the cache is inconsistent with the database.
+ # Possible causes:
+ #
+ # - The database MUST provide a snapshot view for each
+ # session; this error can occur if that requirement is
+ # violated. For example, MySQL's MyISAM engine is not
+ # sufficient for the object_state table because MyISAM
+ # can not provide a snapshot view. (InnoDB is
+ # sufficient.)
+ #
+ # - Something could be writing to the database out
+ # of order, such as a version of RelStorage that
+ # acquires a different commit lock.
+ #
+ # - A software bug. In the past, there was a subtle bug
+ # in after_poll() that caused it to ignore the
+ # transaction order, leading it to sometimes put the
+ # wrong tid in delta_after*.
+
+ cp0, cp1 = self.checkpoints
+ import os
+ import thread
+ raise AssertionError("Detected an inconsistency "
+ "between the RelStorage cache and the database "
+ "while loading an object using the delta_after0 dict. "
+ "Please verify the database is configured for "
+ "ACID compliance and that all clients are using "
+ "the same commit lock. "
+ "(oid_int=%(oid_int)r, tid_int=%(tid_int)r, "
+ "actual_tid_int=%(actual_tid_int)r, "
+ "current_tid=%(current_tid)r, cp0=%(cp0)r, cp1=%(cp1)r, "
+ "len(delta_after0)=%(lda0)r, len(delta_after1)=%(lda1)r, "
+ "pid=%(pid)r, thread_ident=%(thread_ident)r)"
+ % {
+ 'oid_int': oid_int,
+ 'tid_int': tid_int,
+ 'actual_tid_int': actual_tid_int,
+ 'current_tid': self.current_tid,
+ 'cp0': cp0,
+ 'cp1': cp1,
+ 'lda0': len(self.delta_after0),
+ 'lda1': len(self.delta_after1),
+ 'pid': os.getpid(),
+ 'thread_ident': thread.get_ident(),
+ })
+
cache_data = '%s%s' % (p64(tid_int), state or '')
for client in self.clients_local_first:
client.set(cachekey, cache_data)
@@ -419,11 +465,23 @@
# (oid, tid) where tid > after_tid and tid <= last_tid.
changes = self.adapter.poller.list_changes(
cursor, cp1, new_tid_int)
+
+ # Make a dictionary that contains, for each oid, the most
+ # recent tid listed in changes.
+ changes_dict = {}
+ if not isinstance(changes, list):
+ changes = list(changes)
+ changes.sort()
for oid_int, tid_int in changes:
+ changes_dict[oid_int] = tid_int
+
+ # Put the changes in new_delta_after*.
+ for oid_int, tid_int in changes_dict.iteritems():
if tid_int > cp0:
new_delta_after0[oid_int] = tid_int
elif tid_int > cp1:
new_delta_after1[oid_int] = tid_int
+
self.checkpoints = new_checkpoints
self.delta_after0 = new_delta_after0
self.delta_after1 = new_delta_after1
Modified: relstorage/trunk/relstorage/tests/test_cache.py
===================================================================
--- relstorage/trunk/relstorage/tests/test_cache.py 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/relstorage/tests/test_cache.py 2010-07-29 05:32:16 UTC (rev 115183)
@@ -76,6 +76,22 @@
res = c.load(None, 2)
self.assertEqual(res, ('abc', 55))
+ def test_load_using_delta_after0_inconsistent(self):
+ from relstorage.tests.fakecache import data
+ from ZODB.utils import p64
+ adapter = MockAdapter()
+ c = self.getClass()(adapter, MockOptionsWithFakeCache())
+ c.checkpoints = (50, 40)
+ c.delta_after0[2] = 55
+ adapter.mover.data[2] = ('abc', 56)
+ try:
+ c.load(None, 2)
+ except AssertionError, e:
+ print e
+ self.assertTrue('Detected an inconsistency' in e.args[0])
+ else:
+ self.fail("Failed to report cache inconsistency")
+
def test_load_using_checkpoint0_hit(self):
from relstorage.tests.fakecache import data
from ZODB.utils import p64
@@ -297,10 +313,13 @@
data['myprefix:checkpoints'] = '50 40'
adapter = MockAdapter()
c = self.getClass()(adapter, MockOptionsWithFakeCache())
- adapter.poller.changes = [(3, 42), (1, 35), (2, 45)]
+ # Note that OID 3 changed twice. list_changes is not required
+ # to provide the list of changes in order, so simulate
+ # a list of changes that is out of order.
+ adapter.poller.changes = [(3, 42), (1, 35), (2, 45), (3, 41)]
c.checkpoints = (40, 30)
c.current_tid = 40
- c.after_poll(None, 40, 50, [(2, 45)])
+ c.after_poll(None, 40, 50, [(3, 42), (2, 45), (3, 41)])
self.assertEqual(c.checkpoints, (50, 40))
self.assertEqual(data['myprefix:checkpoints'], '50 40')
self.assertEqual(c.delta_after0, {})
Modified: relstorage/trunk/setup.py
===================================================================
--- relstorage/trunk/setup.py 2010-07-28 18:50:14 UTC (rev 115182)
+++ relstorage/trunk/setup.py 2010-07-29 05:32:16 UTC (rev 115183)
@@ -13,7 +13,7 @@
##############################################################################
"""A backend for ZODB that stores pickles in a relational database."""
-VERSION = "1.4.0c1"
+VERSION = "1.4.0c2"
# The choices for the Trove Development Status line:
# Development Status :: 5 - Production/Stable
More information about the checkins
mailing list