Default timescale of 10 seconds.

Now that we understand the nature of the MongoDB timeouts better, it has
become clear that this timescale is only relevant when things are going
wrong, and that happy-path performance is insensitive to this setting.
In that case, a default of 1 second is unnecessarily short.

Author: prdoyle

bosk-mongo/src/main/java/works/bosk/drivers/mongo/MongoDriverSettings.java

@@ -21,7 +21,8 @@ public class MongoDriverSettings {
 	 * are scaled accordingly.
 	 * Lower values recover more quickly, but will also give up sooner
 	 * and cause more network traffic;
-	 * higher values are more patient and efficient, but slower to recover.
+	 * higher values are more patient and efficient, and can tolerate
+	 * longer network disruptions, but are slower to recover.
 	 * <p>
 	 * Under normal circumstances, the system responds promptly
 	 * and efficiently regardless of this setting.
@@ -31,18 +32,20 @@ public class MongoDriverSettings {
 	 * <ul>
 	 *     <li>
 	 *         If you are exercising timeout conditions, set this to a low value
-	 *         (say, 1/10 of its default) to make your tests run quickly;
+	 *         (say, 10x the expected network round-trip delay)
+	 *         to make your tests run quickly;
 	 *     </li>
 	 *     <li>
-	 *         otherwise, set it to a high value (say, 10x its default)
-	 *         to avoid spurious test failures.
+	 *         otherwise, you can set it to a high value (say, 5x its default)
+	 *         to avoid spurious test failures,
+	 *         though the default should also be fine.
 	 *     </li>
 	 * </ul>
 	 *
 	 * In Bosk's own tests, we use even more extreme values to ensure
 	 * this works across a wide range of values.
 	 */
-	@Default int timescaleMS = 1000;
+	@Default int timescaleMS = 10_000;
 
 	/**
 	 * @see DatabaseFormat#SEQUOIA

bosk-mongo/src/main/java/works/bosk/drivers/mongo/internal/MainDriver.java

@@ -522,7 +522,10 @@ public void onConnectionSucceeded() throws
 		private void runInitialRootAction(FutureTask<R> initialRootAction) throws InterruptedException, TimeoutException, InitialRootActionException {
 			initialRootAction.run();
 			try {
-				initialRootAction.get(initializeTimeout, MILLISECONDS);
+				// You might think this ought to have a timeout,
+				// but the underlying initialRootAction logic already has one,
+				// so this already can't run forever.
+				initialRootAction.get();
 				LOGGER.debug("initialRoot action completed successfully");
 			} catch (ExecutionException e) {
 				LOGGER.debug("initialRoot action failed", e);

bosk-mongo/src/test/java/works/bosk/drivers/mongo/internal/MongoDriverRecoveryTest.java

@@ -13,6 +13,7 @@
 import org.bson.Document;
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
 import org.junit.jupiter.params.ParameterizedClass;
 import org.junit.jupiter.params.provider.MethodSource;
 import org.slf4j.Logger;
@@ -26,7 +27,6 @@
 import works.bosk.drivers.mongo.PandoFormat;
 import works.bosk.exceptions.FlushFailureException;
 import works.bosk.exceptions.InvalidTypeException;
-import works.bosk.junit.InjectedTest;
 import works.bosk.testing.drivers.state.TestEntity;
 import works.bosk.testing.junit.Slow;
 
@@ -102,7 +102,7 @@ enum FlushOrWait {
 	}
 
 
-	@InjectedTest
+	@Test
 	@DisruptsMongoProxy
 	void initialOutage_recovers() throws InvalidTypeException, InterruptedException, IOException {
 		LOGGER.debug("Set up the database contents to be different from initialRoot");
@@ -163,20 +163,25 @@ private void waitFor(BoskDriver driver) throws IOException, InterruptedException
 				break;
 			case WAIT:
 				// The user really has no business expecting updates to occur promptly.
-				// Because this is sometimes used when the bosk is (deliberately)
-				// malfunctioning, we should wait much longer than the recovery time.
 				//
-				// Unfortunately, this makes these tests inevitably slow.
+				// This is used in two circumstances:
+				// 1. If the operation is expected to succeed, then the worst-case
+				// delay is the delay time for the connection loop, plus the time
+				// to detect and publish the new format driver,
+				// plus the time to execute the operation itself.
+				// 4*timescaleMS ought to be plenty for all that.
+				// 2. If the operation is expected to fail, no amount of waiting
+				// will make it succeed, so we can ignore this case.
 				//
-				long sleepTime = 12L * driverSettings.timescaleMS();
+				long sleepTime = 4L * driverSettings.timescaleMS();
 				LOGGER.debug("Waiting for {} ms", sleepTime);
 				Thread.sleep(sleepTime);
 				LOGGER.debug("...done waiting");
 				break;
 		}
 	}
 
-	@InjectedTest
+	@Test
 	void databaseDropped_recovers() throws InterruptedException, IOException {
 		testRecovery(() -> {
 			LOGGER.debug("Drop database");
@@ -187,7 +192,7 @@ void databaseDropped_recovers() throws InterruptedException, IOException {
 		}, (_) -> initializeDatabase("after drop"));
 	}
 
-	@InjectedTest
+	@Test
 	void collectionDropped_recovers() throws InterruptedException, IOException {
 		testRecovery(() -> {
 			LOGGER.debug("Drop collection");
@@ -198,7 +203,7 @@ void collectionDropped_recovers() throws InterruptedException, IOException {
 		}, (_) -> initializeDatabase("after drop"));
 	}
 
-	@InjectedTest
+	@Test
 	void documentDeleted_recovers() throws InterruptedException, IOException {
 		testRecovery(() -> {
 			LOGGER.debug("Delete document");
@@ -209,7 +214,7 @@ void documentDeleted_recovers() throws InterruptedException, IOException {
 		}, (_) -> initializeDatabase("after deletion"));
 	}
 
-	@InjectedTest
+	@Test
 	void documentReappears_recovers() throws InterruptedException, IOException {
 		MongoCollection<Document> collection = mongoService.client()
 			.getDatabase(driverSettings.database())
@@ -236,7 +241,7 @@ void documentReappears_recovers() throws InterruptedException, IOException {
 		});
 	}
 
-	@InjectedTest
+	@Test
 	void revisionDeleted_recovers() throws InterruptedException, IOException {
 		// It's not clear that this is a valid test. If this test is a burden to support,
 		// we can consider removing it.
@@ -322,6 +327,12 @@ private void testRecovery(Runnable disruptiveAction, Function<TestEntity, TestEn
 
 		Bosk<TestEntity> bosk = new Bosk<>(boskName(getClass().getSimpleName()), TestEntity.class, AbstractMongoDriverTest::initialRoot, BoskConfig.<TestEntity>builder().driverFactory(driverFactory).build());
 
+		// With short timescales or slow networks, the bosk initial state
+		// can time out trying to read the database and instead uses AbstractMongoDriverTest::initialRoot.
+		// This is actually valid behaviour for a sufficiently impatient user.
+		// Let's wait first to ensure we have the state from the database.
+		waitFor(bosk.driver());
+
 		try (var _ = bosk.readContext()) {
 			// Note: with very short timescales, this assertion can fail because the newly created bosk
 			// times out trying to read the database contents and instead uses AbstractMongoDriverTest::initialRoot.

bosk-mongo/src/test/java/works/bosk/drivers/mongo/internal/TestParameters.java

@@ -14,15 +14,20 @@ public class TestParameters {
 
 	/**
 	 * For tests that are expecting timeouts. A short value makes the tests run faster.
-	 * Too short, and the tests might not be testing the right thing.
+	 * <p>
+	 * Too short, and the tests might end up exhibiting fallback behaviour as though
+	 * there's a database outage. At initialization, it may proceed with the fallback
+	 * initial state from the downstream driver, and other operations may throw
+	 * {@link works.bosk.drivers.mongo.exceptions.DisconnectedException DisconnectException} or similar.
+	 * <p>
 	 * This should be much larger than the expected latency of MongoDB and the network.
 	 */
 	public static final int SHORT_TIMESCALE = 50;
 
 	/**
 	 * For tests that are not expecting timeouts. A nice long value makes spurious test failures unlikely.
 	 */
-	public static final int LONG_TIMESCALE = 90_000;
+	public static final int LONG_TIMESCALE = 150_000;
 
 	@Value
 	public static class ParameterSet {

lib-testing/src/main/resources/logback.xml

@@ -22,8 +22,8 @@
 	<logger name="works.bosk.drivers.mongo" level="DEBUG"/>
 	<logger name="works.bosk.drivers.mongo.internal.ChangeReceiver" level="DEBUG"/>
 	<logger name="works.bosk.drivers.mongo.internal.MainDriver" level="DEBUG"/>
-	<logger name="works.bosk.drivers.mongo.internal.PandoFormatDriver" level="TRACE"/>
-	<logger name="works.bosk.drivers.mongo.internal.AbstractMongoDriverTest" level="INFO"/>
+	<logger name="works.bosk.drivers.mongo.internal.PandoFormatDriver" level="DEBUG"/>
+	<logger name="works.bosk.drivers.mongo.internal.AbstractMongoDriverTest" level="DEBUG"/>
 	<logger name="works.bosk.logback.BoskLogFilter" level="DEBUG"/>
 	 -->