Apache
/
lucene
mirror of https://github.com/apache/lucene.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

SOLR-10109: harden up the assertions in SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds

This commit is contained in:
Chris Hostetter 2017-07-13 11:40:16 -07:00
parent 19fd95b46c
commit d8990db302
1 changed files with 67 additions and 55 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

122
solr/core/src/test/org/apache/solr/update/SoftAutoCommitTest.java
View File

@ -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);
monitor.assertSaneOffers();
// 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));
}
}
// 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 {