You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by da...@apache.org on 2017/07/18 05:13:58 UTC
[06/33] lucene-solr:feature/autoscaling: SOLR-10109: harden up the
assertions in SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds
SOLR-10109: harden up the assertions in SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds
Project: http://git-wip-us.apache.org/repos/asf/lucene-solr/repo
Commit: http://git-wip-us.apache.org/repos/asf/lucene-solr/commit/d8990db3
Tree: http://git-wip-us.apache.org/repos/asf/lucene-solr/tree/d8990db3
Diff: http://git-wip-us.apache.org/repos/asf/lucene-solr/diff/d8990db3
Branch: refs/heads/feature/autoscaling
Commit: d8990db302f5922f4db8138eac00cd77d24e14dc
Parents: 19fd95b
Author: Chris Hostetter <ho...@apache.org>
Authored: Thu Jul 13 11:40:16 2017 -0700
Committer: Chris Hostetter <ho...@apache.org>
Committed: Thu Jul 13 11:40:16 2017 -0700
----------------------------------------------------------------------
.../apache/solr/update/SoftAutoCommitTest.java | 122 ++++++++++---------
1 file changed, 67 insertions(+), 55 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/d8990db3/solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java
----------------------------------------------------------------------
diff --git a/solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java b/solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java
index bd84d32..30496d1 100644
--- a/solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java
+++ b/solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java
@@ -17,6 +17,7 @@
package org.apache.solr.update;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
+import static java.util.concurrent.TimeUnit.NANOSECONDS;
import static org.junit.Assert.assertEquals;
import java.lang.invoke.MethodHandles;
@@ -340,74 +341,85 @@ public class SoftAutoCommitTest extends AbstractSolrTestCase {
hardTracker.setOpenSearcher(false);
// try to add 5 docs really fast
- long fast5start = System.nanoTime();
+
+ final long preFirstNanos = System.nanoTime();
for( int i=0;i<5; i++ ) {
assertU(adoc("id", ""+500 + i, "subject", "five fast docs"));
}
- long fast5end = System.nanoTime() - TimeUnit.NANOSECONDS.convert(300, TimeUnit.MILLISECONDS); // minus a tad of slop
- long fast5time = 1 + TimeUnit.MILLISECONDS.convert(fast5end - fast5start, TimeUnit.NANOSECONDS);
-
- // total time for all 5 adds determines the number of soft to expect
- long expectedSoft = (long)Math.ceil((double) fast5time / softCommitWaitMillis);
- long expectedHard = (long)Math.ceil((double) fast5time / hardCommitWaitMillis);
+ final long postLastNanos = System.nanoTime();
- expectedSoft = Math.max(1, expectedSoft);
- expectedHard = Math.max(1, expectedHard);
-
- // note: counting from 1 for multiplication
- for (int i = 1; i <= expectedSoft; i++) {
- // Wait for the soft commit with plenty of fudge to survive nasty envs
- Long soft = monitor.soft.poll(softCommitWaitMillis * 3, MILLISECONDS);
- if (soft != null || i == 1) {
- assertNotNull(i + ": soft wasn't fast enough", soft);
- monitor.assertSaneOffers();
-
- // have to assume none of the docs were added until
- // very end of the add window
- long softMs = TimeUnit.MILLISECONDS.convert(soft - fast5end, TimeUnit.NANOSECONDS);
- assertTrue(i + ": soft occurred too fast: " +
- softMs + " < (" + softCommitWaitMillis + " * " + i + ")",
- softMs >= (softCommitWaitMillis * i));
- } else {
- // we may have guessed wrong and there were fewer commits
- assertNull("Got a soft commit we weren't expecting", monitor.soft.poll(2000, MILLISECONDS));
- }
- }
+ monitor.assertSaneOffers();
- // note: counting from 1 for multiplication
- for (int i = 1; i <= expectedHard; i++) {
- // wait for the hard commit, shouldn't need any fudge given
- // other actions already taken
- Long hard = monitor.hard.poll(hardCommitWaitMillis, MILLISECONDS);
- assertNotNull(i + ": hard wasn't fast enough", hard);
- monitor.assertSaneOffers();
-
- // have to assume none of the docs were added until
- // very end of the add window
- long hardMs = TimeUnit.MILLISECONDS.convert(hard - fast5end, TimeUnit.NANOSECONDS);
- assertTrue(i + ": hard occurred too fast: " +
- hardMs + " < (" + hardCommitWaitMillis + " * " + i + ")",
- hardMs >= (hardCommitWaitMillis * i));
- }
+ final long maxTimeMillis = MILLISECONDS.convert(postLastNanos - preFirstNanos, NANOSECONDS);
+ log.info("maxTimeMillis: {}ns - {}ns == {}ms", postLastNanos, preFirstNanos, maxTimeMillis);
- // we are only guessing how many commits we may see, allow one extra of each
- monitor.soft.poll(softCommitWaitMillis + 200, MILLISECONDS);
- monitor.hard.poll(hardCommitWaitMillis + 200, MILLISECONDS);
-
- // clear commits
- monitor.hard.clear();
- monitor.soft.clear();
+ // NOTE: explicitly using truncated division of longs to round down
+ // even if evenly divisible, need +1 to account for possible "last" commit triggered by "last" doc
+ final long maxExpectedSoft = 1L + (maxTimeMillis / softCommitWaitMillis);
+ final long maxExpectedHard = 1L + (maxTimeMillis / hardCommitWaitMillis);
+
+ log.info("maxExpectedSoft={}", maxExpectedSoft);
+ log.info("maxExpectedHard={}", maxExpectedHard);
+
+ // do a loop pool over each monitor queue, asserting that:
+ // - we get at least one commit
+ // - we don't get more then the max possible commits expected
+ // - any commit we do get doesn't happen "too fast" relative the previous commit
+ // (or first doc added for the first commit)
+ monitor.assertSaneOffers();
+ assertRapidMultiCommitQueues("softCommit", preFirstNanos, softCommitWaitMillis,
+ maxExpectedSoft, monitor.soft);
+ monitor.assertSaneOffers();
+ assertRapidMultiCommitQueues("hardCommit", preFirstNanos, hardCommitWaitMillis,
+ maxExpectedHard, monitor.hard);
+
+ // now wait a bit...
+ // w/o other action we shouldn't see any additional hard/soft commits
- // wait a bit, w/o other action we shouldn't see any
- // new hard/soft commits
assertNull("Got a hard commit we weren't expecting",
- monitor.hard.poll(1000, MILLISECONDS));
+ monitor.hard.poll(1000, MILLISECONDS));
assertNull("Got a soft commit we weren't expecting",
- monitor.soft.poll(0, MILLISECONDS));
+ monitor.soft.poll(0, MILLISECONDS));
monitor.assertSaneOffers();
}
+
+ /**
+ * Helper method
+ * @see #testSoftAndHardCommitMaxTimeRapidAdds
+ */
+ private static void assertRapidMultiCommitQueues
+ (final String debug, final long startTimestampNanos, final long commitWaitMillis,
+ final long maxNumCommits, final BlockingQueue<Long> queue) throws InterruptedException {
+
+ assert 0 < maxNumCommits;
+
+ // do all our math/comparisons in Nanos...
+ final long commitWaitNanos = NANOSECONDS.convert(commitWaitMillis, MILLISECONDS);
+
+ // these will be modified in each iteration of our assertion loop
+ long prevTimestampNanos = startTimestampNanos;
+ int count = 1;
+ Long commitNanos = queue.poll(commitWaitMillis * 3, MILLISECONDS);
+ assertNotNull(debug + ": did not find a single commit", commitNanos);
+
+ while (null != commitNanos) {
+ if (commitNanos < prevTimestampNanos + commitWaitMillis) {
+ fail(debug + ": commit#" + count + " has TS too low relative to previous TS & commitWait: " +
+ "commitNanos=" + commitNanos + ", prevTimestampNanos=" + prevTimestampNanos +
+ ", commitWaitMillis=" + commitWaitMillis);
+ }
+ if (maxNumCommits < count) {
+ fail(debug + ": commit#" + count + " w/ commitNanos=" + commitNanos +
+ ", but maxNumCommits=" +maxNumCommits);
+ }
+
+ prevTimestampNanos = commitNanos;
+ count++;
+ commitNanos = queue.poll(commitWaitMillis * 3, MILLISECONDS);
+ }
+ }
}
class MockEventListener implements SolrEventListener {