Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Kill leftovers of pre-MVCC read conflicts #320

Merged
merged 1 commit into from Jul 31, 2020

Conversation

navytux
Copy link
Contributor

@navytux navytux commented Jul 21, 2020

In the early days, before MVCC was introduced, ZODB used to raise
ReadConflictError on access to object that was simultaneously changed by
another client in concurrent transaction. However, as
doc/articles/ZODB-overview.rst says

Since Zope 2.8 ZODB has implemented **Multi Version Concurrency Control**.
This means no more ReadConflictErrors, each transaction is guaranteed to be
able to load any object as it was when the transaction begun.

So today the only way to get a ReadConflictError should be at commit time
for an object that was requested to stay unchanged via
checkCurrentSerialInTransaction.

However MVCCAdapterInstance.load(), instead of reporting "no data", was
still raising ReadConflictError for a deleted or not-yet-created object.
If an object is deleted and later requested to be loaded, it should be
"key not found in database", i.e. POSKeyError, not ReadConflictError.
Fix it.

Adjust docstring of ReadConflictError accordingly to explicitly describe
that this error can only happen at commit time for objects requested to
be current.

There were also leftover code, comment and test bits in Connection,
interfaces, transact, testmvcc and testZODB, that are corrected/removed
correspondingly. testZODB actually had ReadConflictTests that was
completely deactivated: commit b0f992f ("Removed the mvcc option..."; 2007)
moved read-conflict-on-access related tests out of ZODBTests, but did not
activated moved parts at all, because as that commit says when MVCC is
always on unconditionally, there is no on-access conflicts:

Removed the mvcc option.  Everybody wants mvcc and removing us lets us
simplify the code a little. (We'll be able to simplify more when we
stop supporting versions.)

Today, if I try to manually activate that ReadConflictTests via

@@ -637,6 +637,7 @@ def __init__(self, poisonedjar):
 def test_suite():
     return unittest.TestSuite((
         unittest.makeSuite(ZODBTests, 'check'),
+        unittest.makeSuite(ReadConflictTests, 'check'),
         ))

 if __name__ == "__main__":

it fails in dumb way showing that this tests were unmaintained for ages:

Error in test checkReadConflict (ZODB.tests.testZODB.ReadConflictTests)
Traceback (most recent call last):
  File "/usr/lib/python2.7/unittest/case.py", line 320, in run
    self.setUp()
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/testZODB.py", line 451, in setUp
    ZODB.tests.utils.TestCase.setUp(self)
AttributeError: 'module' object has no attribute 'utils'

Since today ZODB always uses MVCC and there is no way to get
ReadConflictError on access, those tests should be also gone together
with old pre-MVCC way of handling concurrency.

/cc @jimfulton

@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

CI: py3.7 fails with:

Error in test checkPackNowWhileWriting (ZODB.tests.testMappingStorage.MappingStorageHexTests)
358Traceback (most recent call last):
359  File "/opt/python/3.7.1/lib/python3.7/unittest/case.py", line 59, in testPartExecutor
360    yield
361  File "/opt/python/3.7.1/lib/python3.7/unittest/case.py", line 615, in run
362    testMethod()
363  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/util.py", line 265, in wrapper
364    return func(*args, **kwargs)
365  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/PackableStorage.py", line 284, in checkPackNowWhileWriting
366    self._PackWhileWriting(pack_now=True)
367  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/PackableStorage.py", line 229, in _PackWhileWriting
368    t.join(60)
369  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/MTStorage.py", line 45, in join
370    self._exc_info[0], self._exc_info[1], self._exc_info[2])
371  File "/home/travis/virtualenv/python3.7.1/lib/python3.7/site-packages/six.py", line 693, in reraise
372    raise value
373  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/MTStorage.py", line 37, in run
374    self.runtest()
375  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/tests/PackableStorage.py", line 764, in runtest
376    conn.root()[index].value = MinPO(j)
377  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/Connection.py", line 777, in setstate
378    p, serial = self._storage.load(oid)
379  File "/home/travis/build/zopefoundation/ZODB/src/ZODB/mvccadapter.py", line 155, in load
380    raise POSException.POSKeyError(oid)
381ZODB.POSException.POSKeyError: 0x09

I got this failure at least once locally without my patch. I will try to investigate.

@jamadden
Copy link
Member

Yeah, there's something flaky about that test. A rerun worked correctly. Because that test is about concurrency, that indicates some underlying concurrency issue.

Copy link
Member

@jamadden jamadden left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM!

@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

@jamadden, thanks for feedback rerun and LGTM! I'm still investigating and maybe the failure is indeed related to my patch. I've added the following to debug

--- a/src/ZODB/mvccadapter.py
+++ b/src/ZODB/mvccadapter.py
@@ -152,6 +152,9 @@ def load(self, oid):
         assert self._start is not None
         r = self._storage.loadBefore(oid, self._start)
         if r is None:
+            print('\n\n\nload %d <%s -> None\n\n' % (u64(oid), self._start.encode('hex')))
+            from zodbtools.zodbdump import zodbdump
+            zodbdump(self._storage, None, None, hashonly=True)
             raise POSException.POSKeyError(oid)
         return r[:2]

and got:

load 2359304455393871677 <03d965b437e42567 -> None


txn 03d965b2228ed011 "p"
user ""
description ""
extension ""
obj 0000000000000000 247 sha1:7acd58f6eee385b009eadc660ec2ca1f3e6f57bd -

txn 03d965b3b39fe122 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf8739 59 sha1:cd44d7f625de3e7710978e73fa1b468411bcc5d1 -
obj 20bdeee6ecbf879d 47 sha1:a3b76d91cc32244f57000f46da21bb7f2fc12e36 -

txn 03d965b3b7e42566 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873a 59 sha1:4fb4c03f1f059e96b0e84238fd9bc3351ba7391a -
obj 20bdeee6ecbf879e 47 sha1:33c2cafcc05ff64236d677ba7e33877f2c1edd8a -

txn 03d965b3bc2869aa " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873b 59 sha1:181b552368456699715cfe7e6625d06ca7487b16 -
obj 20bdeee6ecbf879f 47 sha1:44c0fe236805f86997c8bb6de74506b6432a0f56 -

txn 03d965b3c8f53677 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873e 59 sha1:e81d80f6ff0df6ea657ce7e34dfcac7ff09f90a0 -
obj 20bdeee6ecbf87a2 47 sha1:1d960336940734489f134e12c9b08f4e47abf9ee -

txn 03d965b3cd397abb " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873f 59 sha1:8c1f81eab8c16bad77f7ab61947bfe442843400f -
obj 20bdeee6ecbf87a3 47 sha1:b41fe82c7e55ec42edcbc601526c4d8bd5c0fa6c -

txn 03d965b3d17dbf00 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf8740 59 sha1:a63b0a94b9c446eceb8b8b4921a0697e742b4f9f -
obj 20bdeee6ecbf87a4 47 sha1:29a50ad29bac720fce118e0df3c1bb860b796e24 -

txn 03d965b3d5c20344 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf8741 59 sha1:38a6b23994f0c327e3e68ec292149cfb4380c4b6 -
obj 20bdeee6ecbf87a5 47 sha1:4e1b2ac1bb90be9854527c3787ddd0e87bb38bbd -

txn 03d965b3fc2869aa " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873c 59 sha1:5fa75d28ba3de392142773c93a3fe0c046542fc2 -
obj 20bdeee6ecbf87a7 47 sha1:a3b76d91cc32244f57000f46da21bb7f2fc12e36 -

txn 03d965b437e42566 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf8742 59 sha1:bd5a96b145d4b44fe53d8e8e755c8f06518b7bc4 -
obj 20bdeee6ecbf87a8 47 sha1:a3b76d91cc32244f57000f46da21bb7f2fc12e36 -

txn 03d965b45a064788 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873d 59 sha1:d31b1a8f0e139d8ccfc86389570ec188f7bef3fa -
obj 20bdeee6ecbf87a9 47 sha1:33c2cafcc05ff64236d677ba7e33877f2c1edd8a -
    
txn 03d965b4a28ed011 " "
user ""
description ""
extension ""
obj 20bdeee6ecbf873a 59 sha1:f0d711c8dd556e91ba962c147ccf6677bfd69d79 -
obj 20bdeee6ecbf87aa 47 sha1:a3b76d91cc32244f57000f46da21bb7f2fc12e36 -
  
    
  
Error in test checkPackNowWhileWriting (ZODB.tests.testDemoStorage.DemoStorageHexTests)
Traceback (most recent call last):
  File "/usr/lib/python2.7/unittest/case.py", line 329, in run
    testMethod()
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/util.py", line 265, in wrapper
    return func(*args, **kwargs)
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/PackableStorage.py", line 284, in checkPackNowWhileWriting
    self._PackWhileWriting(pack_now=True)
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/PackableStorage.py", line 229, in _PackWhileWriting
    t.join(60)
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/MTStorage.py", line 45, in join
    self._exc_info[0], self._exc_info[1], self._exc_info[2])
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/MTStorage.py", line 37, in run
    self.runtest()
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/PackableStorage.py", line 764, in runtest
    conn.root()[index].value = MinPO(j)
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/Connection.py", line 777, in setstate
    p, serial = self._storage.load(oid)
  File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/mvccadapter.py", line 158, in load
    raise POSException.POSKeyError(oid)
POSKeyError: 0x20bdeee6ecbf873d

After pack object 20bdeee6ecbf873d is added only in transaction

03d965b45a064788

The load comes with before

03d965b437e42567

which is earlier.

The database view as of that before, after pack, should thus indeed see no data for that object. Previously this logic error in the test was hidden becuase there is catch all for ConflictError in every worker, that, if I understand correctly, is there to catch write conflict when changing root[i], but also catches ReadConflictError along the way becuase this class inherits from ConflictError:

try:
index = choice(self.choices)
alist.extend([self.millis(), index])
conn.root()[index].value = MinPO(j)
assign_worked = True
transaction.commit()
alist.append(self.millis())
alist.append('OK')
except ConflictError:
alist.append(self.millis())
alist.append('Conflict')
transaction.abort()

My draft conclusion is that it is incorrect to pack with cut time not before earliest of client, or else, in the presence of such pack, it is expected that database can raise POSKeyError for objects that are removed from under client foot.

Do you agree? (I will try to think about it a bit more)

@jamadden
Copy link
Member

My draft conclusion is that it is incorrect to pack with cut time not before earliest of client, or else, in the presence of such pack, it is expected that database can raise POSKeyError for objects that are removed from under client foot.

I think I agree. Let me put it another way to make sure our understanding is the same:

For storages that do not implement MVCC natively, if a storage has clients viewing it as-of time t, and you perform a pack of that storage as-of time t + n, bad things can happen because objects visible at time t might be removed, causing clients to receive POSKeyError.

Previously, they would have received a ConflictError. That often triggers the client to update their view of the database and retry the transaction, masking any production problems. POSKeyError doesn't receive such special treatment in most applications and would result in a failed transaction.

The options are:

  1. Don't do that. Don't pack to a time after clients are viewing the database. This isn't directly enforceable for all storages: distributed storages like RelStorage can't answer the question "what transaction are clients viewing" (though for RelStorage it doesn't matter because it relies on the native MVCC of the RDBMS to prevent that from being an issue. Mostly.)
    This could be enforced for FileStorage because the information needed lives in a single process. However, it's not clear to me that it's really worth it. Most packs don't pack to now, they pack to a day or two in the past. I think. Maybe all that's needed is a big warning in the documentation.

  2. Make the mvccadapter return to raising some type of ConflictError and revert to the earlier behaviour.
    Semantically that just doesn't seem right to me.

  3. Alter the test to also allow for POSKeyError. That should only happen if mvccadapter is in use or we can otherwise determine that the underlying storage doesn't really support MVCC. I don't want RelStorage to begin raising POSKeyError here and it be allowed, that would indicate breakage in RDBMS transaction isolation.

Thoughts?

@navytux navytux force-pushed the y/readconflict-oncommit-only branch from ae7e656 to fe3d054 Compare July 21, 2020 16:38
@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

@jamadden, thanks for feedback. Our understandings are the same.

Yes, in ideal world we could enforce "don't pack before clients view", but this cannot be easily done with storages like ZEO and NEO which can be used by several clients simultaneously, and ZODB not providing any kind of notification for storages that a client is using it at such and such state.

As much as I don't like it, I guess from backward-compatibility point of view the only way for us is option "2".
Maybe amended a bit to actually detect pack going simultaneously and raising PackConflictError (subclassed from ConflictError) for such case for transaction to be automatically restarted, and POSKeyError only if pack was not going simultaneously. The problem here is that it is not easy with current interfaces to detect that a pack was initiated by another client (from another machine/process), and so with just MVCCAdapter edits, this could be implemented as best-effort only, not 100% reliably. From safety point of view, I would say we should leave MVCCAdapter to raise ReadConflictError as before(*). It seems due to possibility of concurrent pack, which alters database history back of its log, ReadConflictError can still be raised on plain access.

I've amended the patch to return to raising ReadConflictError and only remove parts of code that were actually responsible for regular read-conflicts. The interdiff for amendments is below.

(*) for the reference here is similar place in RelStorage: https://github.com/zodb/relstorage/blob/466168a3/src/relstorage/cache/storage_cache.py#L306-L326

diff --git a/m1.txt b/m2.txt
index 70876d70e..86251022c 100644
--- a/m1.txt
+++ b/m2.txt
@@ -1,4 +1,4 @@
-commit ae7e6564269577330d6cfb58193ed3c4e48b74f9
+commit fe3d0542c3b4f9a5e08ef1e907fd3ab06241406a
 Author: Kirill Smelkov <kirr@nexedi.com>
 Date:   Tue Jul 21 13:13:28 2020 +0300
 
@@ -13,22 +13,29 @@ Date:   Tue Jul 21 13:13:28 2020 +0300
             This means no more ReadConflictErrors, each transaction is guaranteed to be
             able to load any object as it was when the transaction begun.
     
-    So today the only way to get a ReadConflictError should be at commit time
-    for an object that was requested to stay unchanged via
-    checkCurrentSerialInTransaction.
+    So today the only way to get a ReadConflictError should be
     
-    However MVCCAdapterInstance.load(), instead of reporting "no data", was
-    still raising ReadConflictError for a deleted or not-yet-created object.
-    If an object is deleted and later requested to be loaded, it should be
-    "key not found in database", i.e. POSKeyError, not ReadConflictError.
-    Fix it.
+      1) at commit time for an object that was requested to stay unchanged
+         via checkCurrentSerialInTransaction, and
     
-    Adjust docstring of ReadConflictError accordingly to explicitly describe
-    that this error can only happen at commit time for objects requested to
-    be current.
+      2) at plain access time, if a pack running simultaneously to current
+         transaction, removes object revision that we try to load.
+    
+    The second point is a bit unfortunate, since when load discovers that
+    object was deleted or not yet created, it is logically more clean to
+    raise POSKeyError. However due to backward compatibility we still want
+    to raise ReadConflictError in this case - please see comments added to
+    MVCCAdapter for details.
+    
+    Anyway, let's remove leftovers of handling regular read-conflicts from
+    pre-MVCC era:
+    
+    Adjust docstring of ReadConflictError to explicitly describe that this
+    error can only happen at commit time for objects requested to be
+    current.
     
     There were also leftover code, comment and test bits in Connection,
-    interfaces, transact, testmvcc and testZODB, that are corrected/removed
+    interfaces, testmvcc and testZODB, that are corrected/removed
     correspondingly. testZODB actually had ReadConflictTests that was
     completely deactivated: commit b0f992fd ("Removed the mvcc option..."; 2007)
     moved read-conflict-on-access related tests out of ZODBTests, but did not
@@ -61,7 +68,8 @@ Date:   Tue Jul 21 13:13:28 2020 +0300
         AttributeError: 'module' object has no attribute 'utils'
     
     Since today ZODB always uses MVCC and there is no way to get
-    ReadConflictError on access, those tests should be also gone together
-    with old pre-MVCC way of handling concurrency.
+    ReadConflictError on concurrent plain read/write access, those tests
+    should be also gone together with old pre-MVCC way of handling
+    concurrency.
     
     /cc @jimfulton

diff --git a/src/ZODB/POSException.py b/src/ZODB/POSException.py
index 1a833b15d..ed84af776 100644
--- a/src/ZODB/POSException.py
+++ b/src/ZODB/POSException.py
@@ -149,6 +149,12 @@ class ReadConflictError(ConflictError):
     An object was requested to stay not modified via
     checkCurrentSerialInTransaction, and at commit time was found to be
     changed by another transaction (eg. another thread or process).
+
+    Note: for backward compatibility ReadConflictError is also raised on
+    plain object access if
+
+      - object is found to be removed, and
+      - there is possibility that database pack was running simultaneously.
     """
     def __init__(self, message=None, object=None, serials=None, **kw):
         if message is None:
diff --git a/src/ZODB/mvccadapter.py b/src/ZODB/mvccadapter.py
index 4cd7d723d..dc1f77da2 100644
--- a/src/ZODB/mvccadapter.py
+++ b/src/ZODB/mvccadapter.py
@@ -1,3 +1,4 @@
+# -*- coding: utf-8 -*-
 """Adapt IStorage objects to IMVCCStorage
 
 This is a largely internal implementation of ZODB, especially DB and
@@ -9,7 +10,7 @@
 import zope.interface
 
 from . import interfaces, serialize, POSException
-from .utils import p64, u64, Lock
+from .utils import p64, u64, Lock, oid_repr, tid_repr
 
 class Base(object):
 
@@ -152,7 +153,31 @@ def load(self, oid):
         assert self._start is not None
         r = self._storage.loadBefore(oid, self._start)
         if r is None:
-            raise POSException.POSKeyError(oid)
+            # object was deleted or not-yet-created.
+            # raise ReadConflictError - not - POSKeyError due to backward
+            # compatibility: a pack(t+δ) could be running simultaneously to our
+            # transaction that observes database as of t state. Such pack,
+            # because it packs the storage from a "future-to-us" point of view,
+            # can remove object revisions that we can try to load, for example:
+            #
+            #   txn1            <-- t
+            #        obj.revA
+            #
+            #   txn2            <-- t+δ
+            #        obj.revB
+            #
+            # for such case we want user transaction to be restarted - not
+            # failed - by raising ConflictError subclass.
+            #
+            # XXX we don't detect for pack to be actually running - just assume
+            # the worst. It would be good if storage could provide information
+            # whether pack is/was actually running and its details, take that
+            # into account, and raise ReadConflictError only in the presence of
+            # database being simultaneously updated from back of its log.
+            raise POSException.ReadConflictError(
+                    "load %s @%s: object deleted, likely by simultaneous pack" %
+                    (oid_repr(oid), tid_repr(p64(u64(self._start)-1))))
+
         return r[:2]
 
     def prefetch(self, oids):
diff --git a/src/ZODB/tests/testmvcc.py b/src/ZODB/tests/testmvcc.py
index 70152d1b6..d8f13c8ca 100644
--- a/src/ZODB/tests/testmvcc.py
+++ b/src/ZODB/tests/testmvcc.py
@@ -386,7 +386,7 @@
 
 We'll reuse the code from the example above, except that there will
 only be a single revision of "b."  As a result, the attempt to
-activate "b" will result in a POSKeyError.
+activate "b" will result in a ReadConflictError.
 
 >>> ts = TestStorage()
 >>> db = DB(ts)
@@ -413,7 +413,7 @@
 >>> r1["b"]._p_activate() # doctest: +ELLIPSIS
 Traceback (most recent call last):
  ...
-POSKeyError: ...
+ReadConflictError: ...
 
 >>> db.close()
 """
@@ -427,7 +427,7 @@
     (re.compile("b('.*?')"), r"\1"),
     # Python 3 adds module name to exceptions.
     (re.compile("ZODB.POSException.ConflictError"), r"ConflictError"),
-    (re.compile("ZODB.POSException.POSKeyError"), r"POSKeyError"),
+    (re.compile("ZODB.POSException.ReadConflictError"), r"ReadConflictError"),
     ])
 
 def test_suite():
diff --git a/src/ZODB/transact.py b/src/ZODB/transact.py
index 1ffd20ba1..a2927d794 100644
--- a/src/ZODB/transact.py
+++ b/src/ZODB/transact.py
@@ -13,7 +13,7 @@
 ##############################################################################
 """Tools to simplify transactions within applications."""
 
-from ZODB.POSException import ConflictError
+from ZODB.POSException import ReadConflictError, ConflictError
 import transaction
 
 def _commit(note):
@@ -40,7 +40,16 @@ def g(*args, **kwargs):
         n = retries
         while n:
             n -= 1
-            r = f(*args, **kwargs)
+            try:
+                r = f(*args, **kwargs)
+            except ReadConflictError as msg:
+                # the only way ReadConflictError can happen here is due to
+                # simultaneous pack removing objects revision that f could try
+                # to load.
+                transaction.abort()
+                if not n:
+                    raise
+                continue
             try:
                 _commit(note)
             except ConflictError as msg:

@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

The other option is to push ReadConflictError generation into storage drivers - where they know about themselves, whether pack is running, and if yes till which packtime. And then if loadBefore sees object deleted, it can check if that before is earlier then pack time, and then - and only then - generate ReadConflictError.

This would free MVCCStorage from thankless job of guessing whether pack was running or not, and provide possibility to give always correct results with good semantic.

@jamadden
Copy link
Member

As much as I don't like it, I guess from backward-compatibility point of view the only way for us is option "2".

Technically, yes. I question whether that's an actual use case though (who packs to "now"?).

Still, the cost of backwards compatibility isn't very high, and "technically correct is the best kind of correct". So I'm fine with it.

Thanks for tracking that down.

@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

@jamadden, thanks for feedback.

Still, the cost of backwards compatibility isn't very high

Did you mean "is very high" here?

For the reference, after reverting to old behaviour, I'm having trouble for my actual use case which hit the need to remove read conflicts. Now I'm thinking in a way to extend drivers to report last packtime, in case of deletion compare before to that packtime, and report ReadConflict only if before is earlier than packtime, POSKeyError otherwise.

Do you think that would be a good way?

@jamadden
Copy link
Member

Did you mean "is very high" here?

No, I meant "isn't". It's the difference between raising one exception and raising another one.

Now I'm thinking in a way to extend drivers to report last packtime...Do you think that would be a good way?

Not really, no. To me, that sounds like way too much work for what doesn't really seem like a practical problem.

@navytux
Copy link
Contributor Author

navytux commented Jul 21, 2020

I see. If so, and if possible, I prefer to raise POSKeyError for correctness. In this case would the following approach be practically fine with you?

--- a/src/ZODB/DB.py
+++ b/src/ZODB/DB.py
@@ -830,9 +830,24 @@ def pack(self, t=None, days=0):
         the number of days to subtract from t or from the current
         time if t is not specified.
         """
+        hour = 3600
         if t is None:
             t = time.time()
-        t -= days * 86400
+        t -= days * 24 * hour
+
+        # don't allow packtime to start close to head of database log.
+        # this way we practically avoid scenario when concurrent pack can remove
+        # object revisions that "current" connections, started with database view
+        # being a bit earlier than packtime, could try to load.
+        #
+        # If such transaction will impractically last longer than 1 hour, the
+        # worst that could happen is that, in the presense of simultaneous pack,
+        # read for object with removed revision will return POSKeyError instead
+        # of ReadConflictError.
+        head  = self.storage.lastTransaction()
+        thead = TimeStamp(head).timeTime()
+        t = min(t, thead - 1*hour)
+
         try:
             self.storage.pack(t, self.references)
         except:

If yes, I will rework the patch back, and amend the test correspondingly (likely adding dontprotect=True to invokations of pack in tests where pack result is precisely analyzed).

@jamadden
Copy link
Member

I appreciate the thought behind having the DB mutate the parameters the user gives to try to make them "safe" (for FileStorage). But I feel that's a different proposal, and it's not one that I would support. Limitations in one storage engine shouldn't dictate the DB's behaivour in this manner.

If someone is packing a FileStorage to now while simultaneously running transactions against it, that either needs to be fixed in FileStorage (tricky), or documented as "don't do that".

But more to the point, I would be seriously surprised if anyone packs a production system to now while it's running with open transactions and expects reasonable results. If they're trying to pack like that, and are relying on the old behaviour to get application retry to happen. then their transaction is going to take a potentially huge leap forward into a very different state, and it still might fail the same way again — or maybe not; it's inconsistent and unpredictable. In short, I just don't think that's a use case worth worrying about because it's already pretty broken.

@vpelletier
Copy link
Contributor

vpelletier commented Jul 21, 2020

My 2 cents (and hi Kirill !).

I would be seriously surprised if anyone packs a production system to now while it's running with open transactions and expects reasonable results.

...and that such pack would reach any object relevant to ongoing transactions before these transactions are over.

[EDIT]: made above sentence grammatically better.

I mean, the larger the database the longer it takes to pack and the smaller the proportion of objects in active use at any given time. So it will likely take time for the pack to reach any object which is in-use at pack beginning, so the less likely it becomes that such object is still in-use by the time its history gets pruned.

While not all production databases are large, the incentive for packing should grow with database size so smaller databases should be less at risk just because nobody tries to pack them.

Of course, none of this is a very strong guarantee (ex: maybe the application is spending its time modifying the root object on a large database, which will likely be the first to get its history chopped), but these to me point in the direction of these issues being most relevant to toy environments (small database aggressively packed), for which I would personally not tend to optimize if it costs anything for larger environments/more reasonable uses.

Now I'm thinking in a way to extend drivers to report last packtime

I have a faint memory from when I implemented the initial pack support for NEO, but I believe this is already kind of present: if an object got its history trimmed by pack, the oldest kept objectrevision gets the pack time as its "before" pointer whereas a new object creation gets a null "before" pointer. So it is not a global knowledge of packtime, but upon loading an object affected by pack it should be possible to distinguish between a "my snapshot is before object creation" loadBefore (which is likely bogus and deserves a POSKeyError) and one which is trying to access a revision which was pruned (so for which the best we can do is ReadConflictError if I followed this thread right).

A packed creation-undone object is IIRC not detectable after the fact, but in this case my argument above seems even stronger:

  • the transaction started when that object was still reachable
  • then another transaction made that object unreachable, and committed
  • then something discovered that that object is unreachable and committed a transactional creation-undone marker
  • then pack started and eventually reached that object

If the snapshot of the original transaction is still active after all those operations (3 and 4 being likely slow) I would tend to think there are more dubious practices going on than just aggressive packing.

@jimfulton
Copy link
Member

FWIW, with the work we did at ZC, it was very workable to pack a large database while it was running, which we did weekly. We did the GC analysis reading data from a ZRS secondary, and we could do this at our leisure without impacting the primary. When we were done we committed a single transaction that generated a pile of delete records, that were used in subsequent packs.

We always packed to some time in the past, which was useful for auditing and manual recovery from oopsies. :) Packing to some time in the past also mitigated the risk of affecting recent transactions.

FTR, packing never violated transactional integrity unless an application had a bug like holding the only reference to a persistent object in memory.

@navytux
Copy link
Contributor Author

navytux commented Jul 27, 2020

@jamadden, @vpelletier, @jimfulton, thanks for feedback (hi Vincent, glad to see you around ZODB Jim). First of all I appologize for the delay with replying - last few days were a bit crazy on my side. Anyway after thinking about all this overnights:

  1. let's leave present patch as is - to only remove pre-MVCC leftovers without change of semantic. It is prerequisite for change 2.
  2. let's switch MVCCAdapter to raise POSKeyError when load cannot find the object, or sees that it was deleted, and only raise ReadConflictError if load actually detects simultaneous pack that overlaps with MVCCAdapter view of the database. This is [WIP] MVCCAdapter.load: Raise ReadConflictError only if pack is running simultaneously #322 and is implemented via teaching storages to report lastPack time. It is prerequisite for change 3.
  3. let's add loadAt and switch ZODB codebase to it. This fixes DemoStorage corruption (DemoStorage does not take whiteouts into account -> leading to data corruption #318) and offloads storage servers from doing unneccessary work on every object access. In particular this provides potential to reduce 2x number of SQL queries on every load for NEO (DemoStorage does not take whiteouts into account -> leading to data corruption #318 (comment)). This is loadAt #323 and was initial motivation for all this work.

Kirill

@jmuchemb
Copy link
Member

@jamadden wrote:

I question whether that's an actual use case though (who packs to "now"?).

Currently, it's indeed unlikely because it's always good to keep some history in case of recent application regression (fixing data can be easier when old data is easily available).

But with NEO, there's an upcoming new use case. We'll soon rework pack and extend it with partial pack. The idea is minimize the history size of some parts of the ZODB, i.e. packing will be automatic and the cut point will be quite recent. I haven't started to think more about the implementation but an appropriate error when accessing data before pack point might help.

@navytux
Copy link
Contributor Author

navytux commented Jul 31, 2020

@jamadden, this patch was already approved, but it was before I reworked it to actually only remove things without changing semantic. Do you still think that it is ok for it to go in? To me it should be ok, given that here we only remove unused bits and improve ReadConflictError message, but asking for it again just in case.

For the reference: the change of semantic was moved to separate pull requests: #322 and #323.

Thanks beforehand for feedback,
Kirill

Copy link
Member

@jamadden jamadden left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. This is now a minimal internal change whose only visible external effect is a slightly more descriptive error message.

src/ZODB/mvccadapter.py Outdated Show resolved Hide resolved
In the early days, before MVCC was introduced, ZODB used to raise
ReadConflictError on access to object that was simultaneously changed by
another client in concurrent transaction. However, as
doc/articles/ZODB-overview.rst says

	Since Zope 2.8 ZODB has implemented **Multi Version Concurrency Control**.
	This means no more ReadConflictErrors, each transaction is guaranteed to be
	able to load any object as it was when the transaction begun.

So today the only way to get a ReadConflictError should be

  1) at commit time for an object that was requested to stay unchanged
     via checkCurrentSerialInTransaction, and

  2) at plain access time, if a pack running simultaneously to current
     transaction, removes object revision that we try to load.

The second point is a bit unfortunate, since when load discovers that
object was deleted or not yet created, it is logically more clean to
raise POSKeyError. However due to backward compatibility we still want
to raise ReadConflictError in this case - please see comments added to
MVCCAdapter for details.

Anyway, let's remove leftovers of handling regular read-conflicts from
pre-MVCC era:

Adjust docstring of ReadConflictError to explicitly describe that this
error can only happen at commit time for objects requested to be
current, or at plain access if pack is running simultaneously under
connection foot.

There were also leftover code, comment and test bits in Connection,
interfaces, testmvcc and testZODB, that are corrected/removed
correspondingly. testZODB actually had ReadConflictTests that was
completely deactivated: commit b0f992f ("Removed the mvcc option..."; 2007)
moved read-conflict-on-access related tests out of ZODBTests, but did not
activated moved parts at all, because as that commit says when MVCC is
always on unconditionally, there is no on-access conflicts:

    Removed the mvcc option.  Everybody wants mvcc and removing us lets us
    simplify the code a little. (We'll be able to simplify more when we
    stop supporting versions.)

Today, if I try to manually activate that ReadConflictTests via

    @@ -637,6 +637,7 @@ def __init__(self, poisonedjar):
     def test_suite():
         return unittest.TestSuite((
             unittest.makeSuite(ZODBTests, 'check'),
    +        unittest.makeSuite(ReadConflictTests, 'check'),
             ))

     if __name__ == "__main__":

it fails in dumb way showing that this tests were unmaintained for ages:

    Error in test checkReadConflict (ZODB.tests.testZODB.ReadConflictTests)
    Traceback (most recent call last):
      File "/usr/lib/python2.7/unittest/case.py", line 320, in run
        self.setUp()
      File "/home/kirr/src/wendelin/z/ZODB/src/ZODB/tests/testZODB.py", line 451, in setUp
        ZODB.tests.utils.TestCase.setUp(self)
    AttributeError: 'module' object has no attribute 'utils'

Since today ZODB always uses MVCC and there is no way to get
ReadConflictError on concurrent plain read/write access, those tests
should be also gone together with old pre-MVCC way of handling
concurrency.

/cc @jimfulton
/reviewed-on zopefoundation#320
/reviewed-by @jamadden
@navytux navytux force-pushed the y/readconflict-oncommit-only branch from 0d499a3 to 28a0b0c Compare July 31, 2020 11:37
@navytux
Copy link
Contributor Author

navytux commented Jul 31, 2020

@jamadden, thanks for feedback and LGTM. I've incorporated your suggestion into the patch. Let's wait for CI to run and then merge it if all is ok.

interdiff
--- a/COMMIT_MSG.a
+++ b/COMMIT_MSG.b
@@ -73,3 +73,5 @@ Date:   Tue Jul 21 13:13:28 2020 +0300
     concurrency.
     
     /cc @jimfulton
+    /reviewed-on https://github.com/zopefoundation/ZODB/pull/320
+    /reviewed-by @jamadden
--- a/src/ZODB/mvccadapter.py
+++ b/src/ZODB/mvccadapter.py
@@ -176,7 +176,7 @@ def load(self, oid):
             # database being simultaneously updated from back of its log.
             raise POSException.ReadConflictError(
                     "load %s @%s: object deleted, likely by simultaneous pack" %
-                    (oid_repr(oid), tid_repr(p64(u64(self._start)-1))))
+                    (oid_repr(oid), tid_repr(p64(u64(self._start) - 1))))

         return r[:2]

@jamadden
Copy link
Member

If you wouldn't force-push, you wouldn't need to manually paste that "interdiff" and things would be a lot easier for reviewers, both now and in the future when browsing the history of the repository. (Basically I'm asking: please don't force-push. Just push new commits for new changes.)

I forgot to mention that a change note would be appreciated. While this is mostly internal, it does change an exception representation, and that could impact doctests.

@navytux
Copy link
Contributor Author

navytux commented Jul 31, 2020

@jamadden, I see. Ok, I will try, from now on, to push up new fixup commits and squash the result when merging. The short-term history is indeed handy while reviewing patch iterations (that's what interdiff and/or separate fixup pushes are for). However the short-term history is of negative value (imho) when the change is landed into repository into its main history - if someone is navigating through master history, or learning/navigating the codebase via git gui blame, landing into something like "oh, I forgot comma here", or "hm, fixup tests on windows" separately from main change is less convenient and more noise (imho) compared to having only one patch that does one semantic change, for good and without back and forth. That's why I try to produce one patch that does one semantic change and well as the end result. For the reference: github does not support this workflow well, but other systems - e.g. gitlab or gerret do - there you can see interdiff easily via just asking via web menu "please show changes in between patch version X and Y". Anyway, once again, I will try to use the workflow, at least for short-term history, that is easy for you as the reviewer on github.

Regarding change note: if possible, could we please delay it a bit till after going through at least #322 ? Then it will be something like

by default MVCCAdapter.load now raises POSKeyError on access to object that was deleted or not yet created. ReadConflictError, that was raised previously in such situation, is now raised only if there is detected possibility that a pack was running simultaneously with pack time going through MVCCAdapter view of the database.

Is it ok?

@navytux navytux merged commit 3a493b0 into zopefoundation:master Jul 31, 2020
@navytux
Copy link
Contributor Author

navytux commented Jul 31, 2020

( applied the patch to master )

@navytux navytux deleted the y/readconflict-oncommit-only branch July 31, 2020 12:30
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants