[ZODB-Dev] [PATCH] Fix possible data corruption after FileStorage is truncated to roll back a transaction

[Julien Muchembled]

Multi-threaded IO support, which is new to ZODB 3.10, allows clients to read
data (load & loadBefore) even after tpc_vote has started to write a new
transaction to disk. This is done by using different 'file' objects.

Issues start when a transaction is rolled back after data has been appended
(using the writing file object). Truncating is not enough because the FilePool
may have been used in concurrently to read the end of the last transaction:
file objects have their own read buffers which, in this case, may also contain
the beginning of the aborted transaction.

So a solution is to invalidate read buffers whenever they may contain wrong
data. This patch does it on truncation, which happens rarely enough to not
affect performance.

We discovered this bug in the following conditions:
- ZODB splitted in several FileStorage
- many conflicts in the first committed DB, but always resolved
- unresolved conflict in another DB
If the transaction is replayed with success (no more conflict in the other DB),
a subsequent load of the object that could be resolved in the first DB may, for
example, return a wrong serial (tid of the aborted transaction) if the layout
of the committed transaction matches that of the aborted one.

The bug usually manifests with POSKeyError & CorruptedDataError exceptions in
ZEO logs (+ ZEO freeze due to https://github.com/zopefoundation/ZODB/pull/15),
for example while trying to resolve a conflict (and restarting the transaction
does not help, causing Site Errors in Zope).
But theorically, this could also cause silent corruption or unpickling errors
at client side.
---
 src/ZODB/FileStorage/FileStorage.py | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/src/ZODB/FileStorage/FileStorage.py b/src/ZODB/FileStorage/FileStorage.py
index d45cbbf..d662bf4 100644
--- a/src/ZODB/FileStorage/FileStorage.py
+++ b/src/ZODB/FileStorage/FileStorage.py
@@ -683,6 +683,7 @@ def tpc_vote(self, transaction):
                 # Hm, an error occurred writing out the data. Maybe the
                 # disk is full. We don't want any turd at the end.
                 self._file.truncate(self._pos)
+                self._files.flush()
                 raise
             self._nextpos = self._pos + (tl + 8)
 
@@ -737,6 +738,7 @@ def _finish_finish(self, tid):
     def _abort(self):
         if self._nextpos:
             self._file.truncate(self._pos)
+            self._files.flush()
             self._nextpos=0
             self._blob_tpc_abort()
 
@@ -1996,6 +1998,15 @@ def __init__(self, file_name):
         self._out = []
         self._cond = threading.Condition()
 
+    def flush(self):
+        """Empty read buffers.
+
+        This is required if they may contain data of rolled back transactions.
+        """
+        with self.write_lock():
+            for f in self._files:
+                f.flush()
+
     @contextlib.contextmanager
     def write_lock(self):
         with self._cond:
-- 
1.8.5.2.988.g9b015e5.dirty


-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: OpenPGP digital signature
URL: <http://mail.zope.org/pipermail/zodb-dev/attachments/20140211/8adf7b38/attachment.sig>