rishabhdaim commented on code in PR #1779:
URL: https://github.com/apache/jackrabbit-oak/pull/1779#discussion_r1829534632
##########
oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreIT.java:
##########
@@ -188,6 +196,255 @@ public void blockingBlob() throws Exception {
}
}
+ /**
+ * OAK-11184 : a cluster node A is merging a change on root. That involves
two
+ * updates : the first one writing the changes. The second one updating the
+ * commit root (with a revisions=c). If a cluster node B reads the root
while
+ * the commit root was not yet updated, it has to read previous documents
as
+ * part resolving the value of a property in getNodeAtRevision. Only to
find
+ * that the new property does not exist in any previous document and is
thus
+ * non-existent. Cluster node B will have to repeat going through
+ * previous documents whenever reading root - until B is
+ * able to do a backgroundRead. The backgroundRead however could be
blocked by a
+ * number of merge operations - as those merge operations acquire the
+ * backgroundOperationLock - and backgroundRead wants that lock
exclusively.
+ *
+ * The test reproduces only part one of the above (expensiveness of reading
+ * not-yet-visible property of a document with many previous documents).
+ */
+ @Test
+ public void unmergedCommitOnRoot_withPrevNoPropCache() throws Exception {
+ doUnmergedCommitOnRoot(true);
+ }
+
+ /**
+ * This variant tests without the case and is thus expected to fail with
+ * an AssertionError
+ */
+ @Test(expected = AssertionError.class)
+ public void unmergedCommitOnRoot_withoutPrevNoPropCache() throws Exception
{
+ doUnmergedCommitOnRoot(false);
+ }
+
+ private void doUnmergedCommitOnRoot(boolean prevNoPropCacheEnabled) throws
Exception {
+ Clock clock = new Clock.Virtual();
+ clock.waitUntil(System.currentTimeMillis());
+ Revision.setClock(clock);
+ ClusterNodeInfo.setClock(clock);
+
+ FailingDocumentStore fs1 = new FailingDocumentStore(ds);
+ PausableDocumentStore store1 = new PausableDocumentStore(fs1);
+ DocumentNodeStore ns1 =
builderProvider.newBuilder().setClusterId(1).setAsyncDelay(0).clock(clock)
+
.setPrevNoPropCacheFeature(createFeature(prevNoPropCacheEnabled))
+ .setDocumentStore(store1).build();
+
+ NodeBuilder b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", -1);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ // create MANY previous docs
+ System.out.println(new Date() + " - creating MANY previous docs...");
+ for (int j = 0; j < 100; j++) {
+ for (int i = 0; i < NodeDocument.NUM_REVS_THRESHOLD; i++) {
+ b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", i);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+ }
+ ns1.runBackgroundOperations();
+ }
+ System.out.println(new Date() + " - done creating MANY previous
docs.");
+
+ // create /a as some initial content
+ NodeBuilder builder = ns1.getRoot().builder();
+ builder.child("a1").child("b1");
+ builder.child("a2").child("b2");
+ merge(ns1, builder);
+
+ // update a root property (but not via a branch commit)
+ builder = ns1.getRoot().builder();
+ builder.setProperty("rootprop", "v");
+ builder.child("a1").setProperty("nonrootprop", "v");
+ final NodeBuilder finalBuilder = builder;
+ final Semaphore breakpointReachedSemaphore = new Semaphore(0);
+ final Semaphore continueSemaphore = new Semaphore(0);
+ final Thread mergeThread = new Thread(() -> {
+ try {
+ merge(ns1, finalBuilder);
+ } catch (CommitFailedException e) {
+ throw new RuntimeException(e);
+ }
+ });
+ PauseCallback pauseCallback = new PauseCallback() {
+ @Override
+ public PauseCallback handlePause(List<UpdateOp> remainingOps) {
+ breakpointReachedSemaphore.release(1);
+ try {
+ if (!continueSemaphore.tryAcquire(5, TimeUnit.SECONDS)) {
+ System.err.println("timeout");
+ throw new RuntimeException("timeout");
+ }
+ } catch (InterruptedException e) {
+ throw new RuntimeException(e);
+ }
+ return null;
+ }
+ };
+
store1.pauseWith(pauseCallback).on(NODES).on("0:/").after(2).eternally();
+ mergeThread.start();
+ boolean breakpointReached = breakpointReachedSemaphore.tryAcquire(5,
TimeUnit.SECONDS);
+ assertTrue(breakpointReached);
+
+ try {
+ // start B
+ // for MongoDocumentStore (and perhaps others), we can't use the
same
+ // instance by the second DocumentNodeStore, as that would mean
they
+ // share the cache. And it is also the cache that is part of teh
testing.
Review Comment:
```suggestion
// share the cache. And it is also the cache that is part of the
testing.
```
##########
oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreIT.java:
##########
@@ -188,6 +196,255 @@ public void blockingBlob() throws Exception {
}
}
+ /**
+ * OAK-11184 : a cluster node A is merging a change on root. That involves
two
+ * updates : the first one writing the changes. The second one updating the
+ * commit root (with a revisions=c). If a cluster node B reads the root
while
+ * the commit root was not yet updated, it has to read previous documents
as
+ * part resolving the value of a property in getNodeAtRevision. Only to
find
+ * that the new property does not exist in any previous document and is
thus
+ * non-existent. Cluster node B will have to repeat going through
+ * previous documents whenever reading root - until B is
+ * able to do a backgroundRead. The backgroundRead however could be
blocked by a
+ * number of merge operations - as those merge operations acquire the
+ * backgroundOperationLock - and backgroundRead wants that lock
exclusively.
+ *
+ * The test reproduces only part one of the above (expensiveness of reading
+ * not-yet-visible property of a document with many previous documents).
+ */
+ @Test
+ public void unmergedCommitOnRoot_withPrevNoPropCache() throws Exception {
+ doUnmergedCommitOnRoot(true);
+ }
+
+ /**
+ * This variant tests without the case and is thus expected to fail with
+ * an AssertionError
+ */
+ @Test(expected = AssertionError.class)
+ public void unmergedCommitOnRoot_withoutPrevNoPropCache() throws Exception
{
+ doUnmergedCommitOnRoot(false);
+ }
+
+ private void doUnmergedCommitOnRoot(boolean prevNoPropCacheEnabled) throws
Exception {
+ Clock clock = new Clock.Virtual();
+ clock.waitUntil(System.currentTimeMillis());
+ Revision.setClock(clock);
+ ClusterNodeInfo.setClock(clock);
+
+ FailingDocumentStore fs1 = new FailingDocumentStore(ds);
+ PausableDocumentStore store1 = new PausableDocumentStore(fs1);
+ DocumentNodeStore ns1 =
builderProvider.newBuilder().setClusterId(1).setAsyncDelay(0).clock(clock)
+
.setPrevNoPropCacheFeature(createFeature(prevNoPropCacheEnabled))
+ .setDocumentStore(store1).build();
+
+ NodeBuilder b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", -1);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ // create MANY previous docs
+ System.out.println(new Date() + " - creating MANY previous docs...");
Review Comment:
please remove this sout.
##########
oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/Configuration.java:
##########
@@ -106,6 +106,11 @@
description = "Percentage of cache to be allocated towards Diff
cache")
int diffCachePercentage() default DEFAULT_DIFF_CACHE_PERCENTAGE;
+ @AttributeDefinition(
+ name = "PrevNoProp Cache",
+ description = "Percentage of cache to be allocated towards
PrepNoProp cache")
Review Comment:
```suggestion
description = "Percentage of cache to be allocated towards
PrevNoProp cache")
```
##########
oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/Configuration.java:
##########
@@ -106,6 +106,11 @@
description = "Percentage of cache to be allocated towards Diff
cache")
int diffCachePercentage() default DEFAULT_DIFF_CACHE_PERCENTAGE;
+ @AttributeDefinition(
+ name = "PrevNoProp Cache",
+ description = "Percentage of cache to be allocated towards
PrepNoProp cache")
Review Comment:
Also, a one-liner description about this cache would be a good addition.
##########
oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreIT.java:
##########
@@ -188,6 +196,255 @@ public void blockingBlob() throws Exception {
}
}
+ /**
+ * OAK-11184 : a cluster node A is merging a change on root. That involves
two
+ * updates : the first one writing the changes. The second one updating the
+ * commit root (with a revisions=c). If a cluster node B reads the root
while
+ * the commit root was not yet updated, it has to read previous documents
as
+ * part resolving the value of a property in getNodeAtRevision. Only to
find
+ * that the new property does not exist in any previous document and is
thus
+ * non-existent. Cluster node B will have to repeat going through
+ * previous documents whenever reading root - until B is
+ * able to do a backgroundRead. The backgroundRead however could be
blocked by a
+ * number of merge operations - as those merge operations acquire the
+ * backgroundOperationLock - and backgroundRead wants that lock
exclusively.
+ *
+ * The test reproduces only part one of the above (expensiveness of reading
+ * not-yet-visible property of a document with many previous documents).
+ */
+ @Test
+ public void unmergedCommitOnRoot_withPrevNoPropCache() throws Exception {
+ doUnmergedCommitOnRoot(true);
+ }
+
+ /**
+ * This variant tests without the case and is thus expected to fail with
+ * an AssertionError
+ */
+ @Test(expected = AssertionError.class)
+ public void unmergedCommitOnRoot_withoutPrevNoPropCache() throws Exception
{
+ doUnmergedCommitOnRoot(false);
+ }
+
+ private void doUnmergedCommitOnRoot(boolean prevNoPropCacheEnabled) throws
Exception {
+ Clock clock = new Clock.Virtual();
+ clock.waitUntil(System.currentTimeMillis());
+ Revision.setClock(clock);
+ ClusterNodeInfo.setClock(clock);
+
+ FailingDocumentStore fs1 = new FailingDocumentStore(ds);
+ PausableDocumentStore store1 = new PausableDocumentStore(fs1);
+ DocumentNodeStore ns1 =
builderProvider.newBuilder().setClusterId(1).setAsyncDelay(0).clock(clock)
+
.setPrevNoPropCacheFeature(createFeature(prevNoPropCacheEnabled))
+ .setDocumentStore(store1).build();
+
+ NodeBuilder b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", -1);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ // create MANY previous docs
+ System.out.println(new Date() + " - creating MANY previous docs...");
+ for (int j = 0; j < 100; j++) {
+ for (int i = 0; i < NodeDocument.NUM_REVS_THRESHOLD; i++) {
+ b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", i);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+ }
+ ns1.runBackgroundOperations();
+ }
+ System.out.println(new Date() + " - done creating MANY previous
docs.");
Review Comment:
same as above.
##########
oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreIT.java:
##########
@@ -188,6 +196,255 @@ public void blockingBlob() throws Exception {
}
}
+ /**
+ * OAK-11184 : a cluster node A is merging a change on root. That involves
two
+ * updates : the first one writing the changes. The second one updating the
+ * commit root (with a revisions=c). If a cluster node B reads the root
while
+ * the commit root was not yet updated, it has to read previous documents
as
+ * part resolving the value of a property in getNodeAtRevision. Only to
find
+ * that the new property does not exist in any previous document and is
thus
+ * non-existent. Cluster node B will have to repeat going through
+ * previous documents whenever reading root - until B is
+ * able to do a backgroundRead. The backgroundRead however could be
blocked by a
+ * number of merge operations - as those merge operations acquire the
+ * backgroundOperationLock - and backgroundRead wants that lock
exclusively.
+ *
+ * The test reproduces only part one of the above (expensiveness of reading
+ * not-yet-visible property of a document with many previous documents).
+ */
+ @Test
+ public void unmergedCommitOnRoot_withPrevNoPropCache() throws Exception {
+ doUnmergedCommitOnRoot(true);
+ }
+
+ /**
+ * This variant tests without the case and is thus expected to fail with
+ * an AssertionError
+ */
+ @Test(expected = AssertionError.class)
+ public void unmergedCommitOnRoot_withoutPrevNoPropCache() throws Exception
{
+ doUnmergedCommitOnRoot(false);
+ }
+
+ private void doUnmergedCommitOnRoot(boolean prevNoPropCacheEnabled) throws
Exception {
+ Clock clock = new Clock.Virtual();
+ clock.waitUntil(System.currentTimeMillis());
+ Revision.setClock(clock);
+ ClusterNodeInfo.setClock(clock);
+
+ FailingDocumentStore fs1 = new FailingDocumentStore(ds);
+ PausableDocumentStore store1 = new PausableDocumentStore(fs1);
+ DocumentNodeStore ns1 =
builderProvider.newBuilder().setClusterId(1).setAsyncDelay(0).clock(clock)
+
.setPrevNoPropCacheFeature(createFeature(prevNoPropCacheEnabled))
+ .setDocumentStore(store1).build();
+
+ NodeBuilder b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", -1);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ // create MANY previous docs
+ System.out.println(new Date() + " - creating MANY previous docs...");
+ for (int j = 0; j < 100; j++) {
+ for (int i = 0; i < NodeDocument.NUM_REVS_THRESHOLD; i++) {
+ b1 = ns1.getRoot().builder();
+ b1.setProperty("prop", i);
+ ns1.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+ }
+ ns1.runBackgroundOperations();
+ }
+ System.out.println(new Date() + " - done creating MANY previous
docs.");
+
+ // create /a as some initial content
+ NodeBuilder builder = ns1.getRoot().builder();
+ builder.child("a1").child("b1");
+ builder.child("a2").child("b2");
+ merge(ns1, builder);
+
+ // update a root property (but not via a branch commit)
+ builder = ns1.getRoot().builder();
+ builder.setProperty("rootprop", "v");
+ builder.child("a1").setProperty("nonrootprop", "v");
+ final NodeBuilder finalBuilder = builder;
+ final Semaphore breakpointReachedSemaphore = new Semaphore(0);
+ final Semaphore continueSemaphore = new Semaphore(0);
+ final Thread mergeThread = new Thread(() -> {
+ try {
+ merge(ns1, finalBuilder);
+ } catch (CommitFailedException e) {
+ throw new RuntimeException(e);
+ }
+ });
+ PauseCallback pauseCallback = new PauseCallback() {
+ @Override
+ public PauseCallback handlePause(List<UpdateOp> remainingOps) {
+ breakpointReachedSemaphore.release(1);
+ try {
+ if (!continueSemaphore.tryAcquire(5, TimeUnit.SECONDS)) {
+ System.err.println("timeout");
+ throw new RuntimeException("timeout");
+ }
+ } catch (InterruptedException e) {
+ throw new RuntimeException(e);
+ }
+ return null;
+ }
+ };
+
store1.pauseWith(pauseCallback).on(NODES).on("0:/").after(2).eternally();
+ mergeThread.start();
+ boolean breakpointReached = breakpointReachedSemaphore.tryAcquire(5,
TimeUnit.SECONDS);
+ assertTrue(breakpointReached);
+
+ try {
+ // start B
+ // for MongoDocumentStore (and perhaps others), we can't use the
same
+ // instance by the second DocumentNodeStore, as that would mean
they
+ // share the cache. And it is also the cache that is part of teh
testing.
+ // Hence what we need is a real second MongoDocumentStore that
connects
+ // to the same mongo instance (but has its own cache and thus cause
+ // interesting things).
+ // So let's do that here for Mongo (for now - TODO: generalize
this concept)
+ DocumentStore ds2;
+ if (dsf.hasSinglePersistence()) {
+ ds2 = dsf.createDocumentStore(getBuilder().setClusterId(2 /*
likely unnecessary */));
+ } else {
+ // for Memory fixture we need to fall back to single
DocumentStore
+ // (in which case the caching aspect of DocumentStore gets a
bit lost)
+ ds2 = ds;
+ }
+ CountingDocumentStore cds2 = new CountingDocumentStore(ds2);
+ DocumentNodeStore ns2 =
builderProvider.newBuilder().setClusterId(2).setAsyncDelay(0).clock(clock)
+
.setPrevNoPropCacheFeature(createFeature(prevNoPropCacheEnabled))
+ .setDocumentStore(cds2).build();
+
+ // now simulate any write and count how many times
+ // find() had to be invoked (basically to read a previous doc)
+ // if there's more than 95, then that's considered expensive
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v0");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // while the merge in the other thread isn't done, we can repeat
this
+ // and it's still slow
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v1");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // and again, you get the point
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v2");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // doing just another update without any bg work won't fix
anything yet
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v3");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+ // neither does doing just an update on ns2
+ ns2.runBackgroundOperations();
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v4");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // all of the above asserts are "easy" to avoid, as the
+ // revision was indeed not committed yet, and is newly added.
+ // that's a situaiton that can be caught.
+ // It gets a bit more difficult once the revision is committed
+ // but not yet visible. That is hard to catch, as it legitimate
+ // for a revision to be split away while for another cluster node
+ // the only remaining revision is not yet visible (that fact
+ // might give a hint on how this can be fixed, but it is still
hard).
+
+ // so, as soon as we release the other thread and let it finish
+ // its commit, our updates will see the revision being committed
+ // (as side-effect of the merge on root - otherwise there's hardly
+ // a reason to re-resolve the root doc), and subsequently go
+ // into expensive previous document scanning (so the test fails
below).
+ continueSemaphore.release();
+ // let's make sure that other thread is really done
+ mergeThread.join(5000);
+ assertFalse(mergeThread.isAlive());
+
+ // let's check behavior after ns1 finished the commit
+ // but before it did a backgroundWrite
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v5");
+ // with a prevdoc_noprop cache (on root) there will
+ // still be one expensive round of previous document
+ // scans - only thereafter that is cached.
+ // to account for that : we now expect many previous
+ // docs were read:
+ assertPreviousDocsRead(c, 95);
+ }
+
+ // repeating it again should now make use of the prevdoc_noprop
cache
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v6");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // neither does just doing an update on ns1
+ ns1.runBackgroundOperations();
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v7");
+ assertNoPreviousDocsRead(c, 95);
+ // prior to the fix it would have been:
+ // assertPreviousDocsRead(c, 95);
+ }
+
+ // just doing ns1 THEN ns2 will do the trick
+ ns2.runBackgroundOperations();
+ {
+ int c = getNodesFindCountOfAnUpdate(cds2, ns2, "v8");
+ // this worked irrespective of the fix:
+ assertNoPreviousDocsRead(c, 95);
+ }
+ } finally {
+ // in case anyone is still waiting (eg in a test failure case) :
+ continueSemaphore.release();
+ }
+
+ // a bit simplistic, but that's one way to reproduce the bug
+ System.out.println(new Date() + " - success.");
Review Comment:
please remove this as well.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
