This is an automated email from the ASF dual-hosted git repository.
sergehuber pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/unomi.git
The following commit(s) were added to refs/heads/master by this push:
new 38a32b402 UNOMI-970: Fix IT ProgressListener ETA using live suite pace
(#834)
38a32b402 is described below
commit 38a32b402dac75891916cbe68fc61307ef347d27
Author: Serge Huber <[email protected]>
AuthorDate: Tue Jul 21 21:02:31 2026 +0200
UNOMI-970: Fix IT ProgressListener ETA using live suite pace (#834)
---
itests/README.md | 10 +-
.../org/apache/unomi/itests/ProgressListener.java | 82 ++++-
.../apache/unomi/itests/ProgressListenerTest.java | 183 ++++++++++
.../org/apache/unomi/itests/TestTimingCache.java | 247 +++++++++++---
.../apache/unomi/itests/TestTimingCacheTest.java | 375 ++++++++++++++++++++-
5 files changed, 818 insertions(+), 79 deletions(-)
diff --git a/itests/README.md b/itests/README.md
index 0d587d2b4..701debae0 100644
--- a/itests/README.md
+++ b/itests/README.md
@@ -311,9 +311,13 @@ the `itests` module directory (survives `mvn clean`):
`.test-timing-cache-<provider>.properties`
One file per persistence provider (`elasticsearch`, `opensearch`,
`postgresql`, …)
-so ETAs are not mixed across backends. On later runs the listener sums
remaining
-historical times and scales them by how fast/slow the current run is vs history
-(clamped). Safe to delete; missing/unwritable cache falls back to in-run
averages.
+so timings are not mixed across backends. ETA is re-evaluated after every test
from the
+**live pace of substantive completed tests** (real work, excluding
near-instant assume/skip-like
+completions and any failed/aborted test, which are never counted towards
pace); historical
+per-test durations are only hints that reweight remaining work when
harder/easier tests than
+average are still ahead, and that can additionally raise the ETA if completed
tests are
+individually running slower than their own cached history. Safe to delete;
missing/unwritable
+cache falls back to the in-run average.
### Built-in backends
diff --git a/itests/src/test/java/org/apache/unomi/itests/ProgressListener.java
b/itests/src/test/java/org/apache/unomi/itests/ProgressListener.java
index 1ecdca270..0ac12d0d0 100644
--- a/itests/src/test/java/org/apache/unomi/itests/ProgressListener.java
+++ b/itests/src/test/java/org/apache/unomi/itests/ProgressListener.java
@@ -28,6 +28,7 @@ import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.ArrayList;
import java.util.Collections;
+import java.util.HashSet;
import java.util.List;
import java.util.Map;
import java.util.PriorityQueue;
@@ -46,7 +47,7 @@ import java.util.concurrent.atomic.AtomicInteger;
* <li>ASCII art logo display at test suite startup</li>
* <li>Real-time progress bar with percentage completion</li>
* <li>Colorized output (when ANSI is supported)</li>
- * <li>Estimated time remaining from a per-persistence-provider historical
timing cache</li>
+ * <li>Estimated time remaining from live suite pace, with historical
timings as hints</li>
* <li>Test success/failure counters</li>
* <li>Top 10 slowest tests tracking and reporting</li>
* <li>Motivational quotes displayed at progress milestones</li>
@@ -99,6 +100,18 @@ public class ProgressListener extends RunListener {
"Hardships often prepare ordinary people for an extraordinary
destiny. - C.S. Lewis"
};
+ /**
+ * A single successfully-completed test's duration this run, with its
historical cached duration
+ * when one exists. Replaces what used to be two separately-mutated
parallel lists (durations, and
+ * observed-vs-cached pairs) with one sample per completed test, so the
two views derived from it
+ * (see {@link #estimateRemainingTime}) can never desync from each other.
+ */
+ private record CompletedSample(long durationMs, Long cachedMs) {
+ boolean hasHistoricalMatch() {
+ return cachedMs != null && cachedMs > 0L;
+ }
+ }
+
/**
* Inner class representing a test execution time record.
* Used to track individual test performance for reporting the slowest
tests.
@@ -144,6 +157,13 @@ public class ProgressListener extends RunListener {
* timing cache (aborted / assertion failures skew historical ETAs).
*/
private boolean currentTestFailed;
+ /**
+ * Set in {@link #testAssumptionFailure} before {@link #testFinished}. An
{@code Assume}-based skip
+ * is not a failure (JUnit does not count it as one — see {@link
#testAssumptionFailure}), but its
+ * duration must be excluded from the timing cache/live pace the same way
a hard failure's is, or a
+ * capability-check test that occasionally short-circuits via assume would
pollute its own history.
+ */
+ private boolean currentTestAssumptionFailed;
/** Formatter for human-readable timestamps */
private static final DateTimeFormatter TIMESTAMP_FORMATTER =
DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss");
@@ -153,10 +173,8 @@ public class ProgressListener extends RunListener {
private final Map<String, Long> cachedTimings;
/** Timing-cache keys for tests not yet completed in this run */
private final Set<String> remainingTestKeys;
- /** Durations (ms) of tests completed in this run */
- private final List<Long> completedDurations = new CopyOnWriteArrayList<>();
- /** Pairs of [observedMs, cachedMs] for completed tests that had a
historical entry */
- private final List<long[]> observedVsCached = new CopyOnWriteArrayList<>();
+ /** Samples for tests completed successfully in this run; see {@link
CompletedSample}. */
+ private final List<CompletedSample> completedSamples = new
CopyOnWriteArrayList<>();
/**
* Creates a new ProgressListener instance.
@@ -288,6 +306,7 @@ public class ProgressListener extends RunListener {
@Override
public void testStarted(Description description) {
currentTestFailed = false;
+ currentTestAssumptionFailed = false;
startTestTime = System.currentTimeMillis();
// Print test start boundary with test name
String testName = extractTestName(description);
@@ -312,7 +331,9 @@ public class ProgressListener extends RunListener {
long endTestTime = System.currentTimeMillis();
long testDuration = endTestTime - startTestTime;
boolean failed = currentTestFailed;
+ boolean skippedByAssumption = currentTestAssumptionFailed;
currentTestFailed = false;
+ currentTestAssumptionFailed = false;
completedTests.incrementAndGet();
successfulTests.incrementAndGet(); // Default to success unless a
failure is recorded separately.
@@ -324,14 +345,11 @@ public class ProgressListener extends RunListener {
String testKey = TestTimingCache.keyFor(description);
remainingTestKeys.remove(testKey);
- // Persist only successes: failure/abort durations pollute the
provider cache and ETA scale.
- // Write after every successful test (not only at suite end) so Ctrl-C
/ CI kill keeps progress.
- if (!failed) {
- completedDurations.add(testDuration);
- Long historical = cachedTimings.get(testKey);
- if (historical != null && historical > 0L) {
- observedVsCached.add(new long[]{testDuration, historical});
- }
+ // Persist only substantive successes: a hard failure's or an
assume-based skip's duration must
+ // not pollute the provider cache/ETA pace. Write after every such
test (not only at suite end)
+ // so Ctrl-C / CI kill keeps progress.
+ if (!failed && !skippedByAssumption) {
+ completedSamples.add(new CompletedSample(testDuration,
cachedTimings.get(testKey)));
TestTimingCache.save(persistenceProvider,
Collections.singletonMap(testKey, testDuration));
}
@@ -360,6 +378,20 @@ public class ProgressListener extends RunListener {
displayProgress();
}
+ /**
+ * Called when a test aborts via {@code Assume.assumeTrue}/{@code
assumeFalse} (before
+ * {@link #testFinished}). JUnit does not treat this as a failure — {@link
Result#wasSuccessful()}
+ * is unaffected and success/failure counters here are intentionally left
untouched — but the test's
+ * duration must still be excluded from the timing cache/live pace, or a
capability-gated test (e.g.
+ * {@code RolloverIT}) that occasionally short-circuits via assume would
pollute its own history.
+ *
+ * @param failure the assumption-failure information
+ */
+ @Override
+ public void testAssumptionFailure(Failure failure) {
+ currentTestAssumptionFailed = true;
+ }
+
/**
* Called when a test fails (before {@link #testFinished}). Marks the test
so its duration is
* not written to the timing cache.
@@ -493,14 +525,21 @@ public class ProgressListener extends RunListener {
}
/**
- * Estimates remaining time using the provider-specific {@link
TestTimingCache}, scaled by how
- * fast/slow this run has been vs history for tests that already completed
with a cache hit.
+ * Estimates remaining time from the live pace of substantive completed
tests, using the
+ * provider-specific {@link TestTimingCache} as hints for how heavy the
remaining tests are.
*
- * @param completed the number of tests completed so far
* @param elapsedTime the time elapsed since the run started, in
milliseconds
* @return the estimated remaining time, in milliseconds
*/
- private long estimateRemainingTime(int completed, long elapsedTime) {
+ private long estimateRemainingTime(long elapsedTime) {
+ List<Long> completedDurations = new
ArrayList<>(completedSamples.size());
+ List<TestTimingCache.TimingSample> observedVsCached = new
ArrayList<>();
+ for (CompletedSample sample : completedSamples) {
+ completedDurations.add(sample.durationMs());
+ if (sample.hasHistoricalMatch()) {
+ observedVsCached.add(new
TestTimingCache.TimingSample(sample.durationMs(), sample.cachedMs()));
+ }
+ }
return TestTimingCache.estimateRemainingMs(
remainingTestKeys,
cachedTimings,
@@ -509,6 +548,13 @@ public class ProgressListener extends RunListener {
elapsedTime);
}
+ /**
+ * Test-support accessor for the timing-cache keys not yet completed in
this run.
+ */
+ Set<String> remainingTestKeysSnapshot() {
+ return new HashSet<>(remainingTestKeys);
+ }
+
/**
* Displays the current progress of the test run including progress bar,
* percentage completion, estimated time remaining, and success/failure
counts.
@@ -518,7 +564,7 @@ public class ProgressListener extends RunListener {
int completed = completedTests.get();
long elapsedTime = System.currentTimeMillis() - startTime;
- long estimatedRemainingTime = estimateRemainingTime(completed,
elapsedTime);
+ long estimatedRemainingTime = estimateRemainingTime(elapsedTime);
String progressBar = generateProgressBar(((double) completed /
totalTests) * 100);
String humanReadableTime = formatTime(estimatedRemainingTime);
diff --git
a/itests/src/test/java/org/apache/unomi/itests/ProgressListenerTest.java
b/itests/src/test/java/org/apache/unomi/itests/ProgressListenerTest.java
new file mode 100644
index 000000000..ade7b2ce6
--- /dev/null
+++ b/itests/src/test/java/org/apache/unomi/itests/ProgressListenerTest.java
@@ -0,0 +1,183 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.unomi.itests;
+
+import org.apache.unomi.itests.persistence.PersistenceITBackendResolver;
+import org.junit.After;
+import org.junit.Assert;
+import org.junit.AssumptionViolatedException;
+import org.junit.Before;
+import org.junit.Test;
+import org.junit.runner.Description;
+import org.junit.runner.notification.Failure;
+
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.util.Arrays;
+import java.util.concurrent.atomic.AtomicInteger;
+
+/**
+ * Exercises {@link ProgressListener}'s actual JUnit {@code RunListener}
callback wiring — as opposed to
+ * {@link TestTimingCacheTest}, which only exercises {@link TestTimingCache}'s
pure helpers directly with
+ * hand-built inputs. In particular this covers the {@code
currentTestFailed}/{@code
+ * currentTestAssumptionFailed} flag lifecycle across {@code
testStarted}/{@code testFailure}/{@code
+ * testAssumptionFailure}/{@code testFinished}, which decides whether a
completed test's duration reaches
+ * {@link TestTimingCache}.
+ */
+public class ProgressListenerTest {
+
+ /** Comfortably above {@link TestTimingCache#SUBSTANTIVE_OBSERVED_MS} so
save() doesn't filter it out. */
+ private static final long SUBSTANTIVE_SLEEP_MS = 150L;
+
+ private String previousUserDir;
+ private Path tempDir;
+
+ @Before
+ public void setUp() throws Exception {
+ previousUserDir = System.getProperty("user.dir");
+ tempDir = Files.createTempDirectory("unomi-progress-listener-test");
+ System.setProperty("user.dir", tempDir.toAbsolutePath().toString());
+ }
+
+ @After
+ public void tearDown() {
+ if (previousUserDir != null) {
+ System.setProperty("user.dir", previousUserDir);
+ }
+ }
+
+ private static Description descriptionFor(String methodName) {
+ return Description.createTestDescription(ProgressListenerTest.class,
methodName);
+ }
+
+ private static ProgressListener newListener(String... testKeys) {
+ return new ProgressListener(testKeys.length, new AtomicInteger(0),
Arrays.asList(testKeys));
+ }
+
+ private static String provider() {
+ return PersistenceITBackendResolver.resolveProviderId();
+ }
+
+ @Test
+ public void successfulTestPersistsDurationToTimingCache() throws Exception
{
+ ProgressListener listener = newListener("ProgressListenerTest#ok");
+ Description description = descriptionFor("ok");
+
+ listener.testStarted(description);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testFinished(description);
+
+ Long persisted =
TestTimingCache.load(provider()).get("ProgressListenerTest#ok");
+ Assert.assertNotNull("a successful test's duration should be persisted
to the timing cache", persisted);
+ Assert.assertTrue(persisted > 0L);
+ }
+
+ @Test
+ public void failedTestDurationIsNotPersistedToTimingCache() throws
Exception {
+ ProgressListener listener =
newListener("ProgressListenerTest#failing");
+ Description description = descriptionFor("failing");
+
+ listener.testStarted(description);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testFailure(new Failure(description, new
AssertionError("boom")));
+ listener.testFinished(description);
+
+ Assert.assertNull("a failed test's duration must not pollute the
timing cache",
+
TestTimingCache.load(provider()).get("ProgressListenerTest#failing"));
+ }
+
+ @Test
+ public void assumptionFailureDurationIsNotPersistedToTimingCache() throws
Exception {
+ // Regression coverage: ProgressListener must override
testAssumptionFailure (JUnit's callback
+ // for Assume.assumeTrue/assumeFalse-based skips, e.g. RolloverIT's
backend-capability gating) —
+ // without it, an assume-skipped test flows through testFinished
exactly like a success and its
+ // duration would be persisted.
+ ProgressListener listener =
newListener("ProgressListenerTest#skipped");
+ Description description = descriptionFor("skipped");
+
+ listener.testStarted(description);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testAssumptionFailure(new Failure(description,
+ new AssumptionViolatedException("backend does not support
this")));
+ listener.testFinished(description);
+
+ Assert.assertNull("an assume-skipped test's duration must not pollute
the timing cache",
+
TestTimingCache.load(provider()).get("ProgressListenerTest#skipped"));
+ }
+
+ @Test
+ public void currentTestFlagsResetBetweenTests() throws Exception {
+ // A failure on test #1 must not suppress the timing-cache write for
test #2.
+ ProgressListener listener = newListener("ProgressListenerTest#first",
"ProgressListenerTest#second");
+ Description first = descriptionFor("first");
+ Description second = descriptionFor("second");
+
+ listener.testStarted(first);
+ listener.testFailure(new Failure(first, new AssertionError("boom")));
+ listener.testFinished(first);
+
+ listener.testStarted(second);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testFinished(second);
+
+
Assert.assertNull(TestTimingCache.load(provider()).get("ProgressListenerTest#first"));
+ Assert.assertNotNull("the failed flag must reset so the next test
persists normally",
+
TestTimingCache.load(provider()).get("ProgressListenerTest#second"));
+ }
+
+ @Test
+ public void currentTestAssumptionFlagResetsBetweenTests() throws Exception
{
+ // Same as currentTestFlagsResetBetweenTests, but for the
assumption-failure flag specifically.
+ ProgressListener listener =
newListener("ProgressListenerTest#skippedFirst", "ProgressListenerTest#second");
+ Description first = descriptionFor("skippedFirst");
+ Description second = descriptionFor("second");
+
+ listener.testStarted(first);
+ listener.testAssumptionFailure(new Failure(first, new
AssumptionViolatedException("skip")));
+ listener.testFinished(first);
+
+ listener.testStarted(second);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testFinished(second);
+
+
Assert.assertNull(TestTimingCache.load(provider()).get("ProgressListenerTest#skippedFirst"));
+ Assert.assertNotNull("the assumption-failed flag must reset so the
next test persists normally",
+
TestTimingCache.load(provider()).get("ProgressListenerTest#second"));
+ }
+
+ @Test
+ public void ignoredTestIsRemovedFromRemainingKeys() {
+ ProgressListener listener =
newListener("ProgressListenerTest#ignoredOne", "ProgressListenerTest#other");
+ listener.testIgnored(descriptionFor("ignoredOne"));
+
+
Assert.assertFalse(listener.remainingTestKeysSnapshot().contains("ProgressListenerTest#ignoredOne"));
+
Assert.assertTrue(listener.remainingTestKeysSnapshot().contains("ProgressListenerTest#other"));
+ }
+
+ @Test
+ public void finishedTestIsRemovedFromRemainingKeys() throws Exception {
+ ProgressListener listener = newListener("ProgressListenerTest#done",
"ProgressListenerTest#other");
+ Description description = descriptionFor("done");
+
+ listener.testStarted(description);
+ Thread.sleep(SUBSTANTIVE_SLEEP_MS);
+ listener.testFinished(description);
+
+
Assert.assertFalse(listener.remainingTestKeysSnapshot().contains("ProgressListenerTest#done"));
+
Assert.assertTrue(listener.remainingTestKeysSnapshot().contains("ProgressListenerTest#other"));
+ }
+}
diff --git a/itests/src/test/java/org/apache/unomi/itests/TestTimingCache.java
b/itests/src/test/java/org/apache/unomi/itests/TestTimingCache.java
index f6e5b7e55..127951db2 100644
--- a/itests/src/test/java/org/apache/unomi/itests/TestTimingCache.java
+++ b/itests/src/test/java/org/apache/unomi/itests/TestTimingCache.java
@@ -56,10 +56,46 @@ final class TestTimingCache {
/**
* Clamp for the live-run vs historical scale factor so a few outliers
cannot make ETA absurd.
+ * Used by {@link #computeScale}; {@link #estimateRemainingMs} uses the
live substantive-test
+ * average as its primary pace signal and only applies this scale as an
additional boost when
+ * completed tests are individually slower than their cached history.
*/
static final double MIN_SCALE = 0.25;
static final double MAX_SCALE = 4.0;
+ /**
+ * Observed durations below this are treated as non-representative for
pace/scale purposes
+ * (assumes / skipped-in-substance tests that return almost instantly).
+ */
+ static final long SUBSTANTIVE_OBSERVED_MS = 100L;
+
+ /**
+ * Ignore a pair in {@link #computeScale} when its cached entry is more
than this many times
+ * bigger than what was actually observed. This only ever applies to pairs
that already passed the
+ * {@link #SUBSTANTIVE_OBSERVED_MS} gate (i.e. {@code observed} is not
itself assume/skip-like) but
+ * are still disproportionately faster than their own cached history — an
outlier that would
+ * otherwise drag the scale toward {@link #MIN_SCALE}. This is
intentionally one-directional: a pair
+ * where {@code observed} is much bigger than {@code cached} is a genuine
regression signal and is
+ * not excluded, so it can still raise the ETA.
+ */
+ static final double MAX_PAIR_SKEW = 20.0;
+
+ /**
+ * Upper bound for the true-cold-start placeholder average in {@link
#fallbackAverageMs} (no
+ * completed test and no historical cache at all). Growing with elapsed
time keeps the ETA display
+ * from looking frozen while nothing has finished yet, but must stay
capped — otherwise a run that
+ * stalls (e.g. several early failures with nothing successful yet) would
balloon the placeholder,
+ * and therefore the ETA for every remaining test, to an implausibly large
number.
+ */
+ static final long COLD_START_PLACEHOLDER_CAP_MS = 60_000L;
+
+ /**
+ * An (observed, cached) duration sample for a single completed test that
had a historical cache
+ * entry, used by {@link #computeScale} to judge live pace vs history for
individual tests.
+ */
+ record TimingSample(long observedMs, long cachedMs) {
+ }
+
private TestTimingCache() {
}
@@ -122,7 +158,8 @@ final class TestTimingCache {
try {
timings.put(key, Long.parseLong(props.getProperty(key)));
} catch (NumberFormatException e) {
- // Ignore a malformed entry rather than failing the whole
cache load
+ LOGGER.debug("Ignoring malformed test timing cache entry {}={}
in {}: {}",
+ key, props.getProperty(key), cacheFile,
e.getMessage());
}
}
return timings;
@@ -132,6 +169,10 @@ final class TestTimingCache {
* Merges freshly observed durations into the persisted cache for the
given persistence provider,
* smoothing each updated entry with an exponential moving average so a
single unusually slow/fast
* run doesn't swing future ETAs too far.
+ * <p>
+ * Durations below {@link #SUBSTANTIVE_OBSERVED_MS} (assume/skip-like) are
ignored entirely rather
+ * than blended in — a test that occasionally short-circuits via an early
assume/skip would
+ * otherwise gradually drag its historical average down toward that
non-representative value.
*
* @param persistenceProvider provider id the run just executed against
* @param observedTimings durations (in milliseconds) observed during the
run that just finished
@@ -143,82 +184,163 @@ final class TestTimingCache {
Path cacheFile = cacheFile(persistenceProvider);
try {
Map<String, Long> merged = load(persistenceProvider);
+ boolean changed = false;
for (Map.Entry<String, Long> entry : observedTimings.entrySet()) {
+ Long observed = entry.getValue();
+ if (observed == null || observed < SUBSTANTIVE_OBSERVED_MS) {
+ continue;
+ }
Long previous = merged.get(entry.getKey());
long updated = previous == null
- ? entry.getValue()
- : Math.round(previous * (1 - SMOOTHING) +
entry.getValue() * SMOOTHING);
+ ? observed
+ : Math.round(previous * (1 - SMOOTHING) + observed *
SMOOTHING);
merged.put(entry.getKey(), updated);
+ changed = true;
+ }
+ if (!changed) {
+ return;
}
Properties props = new Properties();
merged.forEach((key, value) -> props.setProperty(key,
String.valueOf(value)));
Path parent = cacheFile.toAbsolutePath().getParent();
Path tempFile = Files.createTempFile(parent, "test-timing-cache",
".tmp");
- try (Writer writer = Files.newBufferedWriter(tempFile,
StandardCharsets.UTF_8)) {
- props.store(writer, "Apache Unomi IT test timing cache per
persistence provider "
- + "(local dev aid, safe to delete)");
+ try {
+ try (Writer writer = Files.newBufferedWriter(tempFile,
StandardCharsets.UTF_8)) {
+ props.store(writer, "Apache Unomi IT test timing cache per
persistence provider "
+ + "(local dev aid, safe to delete)");
+ }
+ Files.move(tempFile, cacheFile,
StandardCopyOption.REPLACE_EXISTING);
+ } finally {
+ // Best-effort cleanup only: after a successful move this is
already gone, and any
+ // exception here must not mask a real failure from the
write/move above.
+ try {
+ Files.deleteIfExists(tempFile);
+ } catch (IOException ignored) {
+ // Nothing more we can do; the temp file is harmless local
dev-workspace clutter.
+ }
}
- Files.move(tempFile, cacheFile,
StandardCopyOption.REPLACE_EXISTING);
- } catch (IOException | RuntimeException e) {
+ } catch (IOException e) {
LOGGER.debug("Unable to persist test timing cache at {} (ETAs will
just use the in-run average next time): {}",
cacheFile, e.getMessage());
+ } catch (RuntimeException e) {
+ // Distinct from the expected-I/O-failure case above: an
unexpected exception here means a
+ // real bug in the merge/blend logic, not just a
read-only/ephemeral workspace.
+ LOGGER.warn("Unexpected error persisting test timing cache at {}
(ETAs will just use the in-run average next time)",
+ cacheFile, e);
}
}
/**
* Estimates remaining wall time for unfinished tests.
* <p>
- * For each remaining test with a historical entry, uses that duration
scaled by how fast/slow
- * <em>this</em> run has been relative to history (ratio of observed vs
cached for completed
- * tests that had a cache hit). Uncached remaining tests use the in-run
average of completed
- * durations (or the median of historical values when nothing has
completed yet).
+ * <strong>Live pace is primary:</strong> the pace is the average duration
of <em>substantive</em>
+ * completed tests this run (real work, excluding near-instant
assume/skip-like completions — see
+ * {@link #SUBSTANTIVE_OBSERVED_MS}). Historical per-test durations are
only <em>hints</em> that
+ * reweight remaining work by how each remaining test's historical
duration compares to the suite's
+ * average historical duration — a block of historically slow tests still
ahead raises the ETA above
+ * a flat per-test rate, and a tail of historically light tests lowers it
below that rate.
+ * <p>
+ * Deriving pace from substantive durations only — rather than {@code
elapsedTimeMs / completed}
+ * over every finished test — avoids two failure modes: (1) the caller
never adds a failed or
+ * assume-aborted test's duration to {@code completedDurations} (see
{@link ProgressListener}), so
+ * its wall time cannot inflate the pace the way a naive elapsed/count
ratio would; (2) a run of fast
+ * assumes/skips before a block of heavy tests cannot drag the pace toward
zero, since those
+ * near-instant completions are excluded from the average rather than
counted as "typical" tests.
+ * <p>
+ * A global “this run is 4× faster than cache” scale is <em>not</em>
applied to shrink remaining
+ * historical time — that is what made ETAs chronically too low after
early assumes/skips.
+ * If the run is <em>slower</em> than cache on substantive tests,
remaining historical time is still
+ * raised accordingly via {@link #computeScale}.
+ * <p>
+ * Cold start (no completed test yet, substantive or not) falls back to
the historical average pace,
+ * so remaining tests are estimated at their full cached weight until real
live data says otherwise.
*
* @param remainingKeys keys still expected to run
* @param cachedTimings historical durations for this persistence provider
- * @param observedVsCachedCompleted pairs of (observedMs, cachedMs) for
completed tests that had history
- * @param completedDurations all completed durations this run (for
fallback average)
- * @param elapsedTimeMs wall time since suite start (unused for sum; kept
for API clarity)
+ * @param observedVsCachedCompleted samples of (observedMs, cachedMs) for
completed tests that had history
+ * @param completedDurations successful completed durations this run (for
live pace and fallback average)
+ * @param elapsedTimeMs wall time since suite start; only its sign is
used, to detect the cold-start case
* @return estimated remaining milliseconds (never negative)
*/
static long estimateRemainingMs(Collection<String> remainingKeys,
Map<String, Long> cachedTimings,
- Collection<long[]>
observedVsCachedCompleted,
+ Collection<TimingSample>
observedVsCachedCompleted,
Collection<Long> completedDurations,
long elapsedTimeMs) {
- double scale = computeScale(observedVsCachedCompleted);
+ int remainingCount = remainingKeys == null ? 0 : remainingKeys.size();
+ if (remainingCount == 0) {
+ return 0L;
+ }
+
+ int completedCount = completedDurations == null ? 0 :
completedDurations.size();
double fallbackAvg = fallbackAverageMs(completedDurations,
cachedTimings, elapsedTimeMs);
+ // fallbackAvg is guaranteed > 0 (see fallbackAverageMs), so this is
always positive too.
+ double globalHintAvg = averagePositive(cachedTimings != null ?
cachedTimings.values() : null);
+ if (globalHintAvg <= 0.0) {
+ globalHintAvg = fallbackAvg;
+ }
- long estimate = 0L;
+ long hintRemainingMs = 0L;
for (String key : remainingKeys) {
- Long cached = cachedTimings.get(key);
+ Long cached = cachedTimings != null ? cachedTimings.get(key) :
null;
if (cached != null && cached > 0L) {
- estimate += Math.round(cached * scale);
+ hintRemainingMs += cached;
} else {
- estimate += Math.round(fallbackAvg);
+ hintRemainingMs += Math.round(fallbackAvg);
}
}
- return Math.max(0L, estimate);
+
+ // Cold start: only historical hints (or placeholder average) are
available.
+ if (completedCount <= 0 || elapsedTimeMs <= 0L) {
+ return Math.max(0L, hintRemainingMs);
+ }
+
+ // Live pace comes only from substantive completions so neither a
batch of trivial
+ // assume/skip successes nor (by construction — see caller) any
failed/aborted test's wall
+ // time can skew it; fall back to the historical average until we have
such a data point.
+ double substantiveAvgMs = averageAtLeast(completedDurations,
SUBSTANTIVE_OBSERVED_MS);
+ double avgActualMs = substantiveAvgMs > 0.0 ? substantiveAvgMs :
globalHintAvg;
+
+ // Weight remaining work by how each remaining test's historical
duration compares to the
+ // suite's average historical duration, then rescale that shape to
today's live pace:
+ // predict(r) = avgActual * (hint(r) / globalHintAvg)
+ // sum = hintRemaining * avgActual / globalHintAvg
+ // This is genuinely bidirectional: it raises the ETA above a flat
live-pace rate when the
+ // remaining tests are historically heavier than average, and lowers
it below that rate when
+ // they're historically lighter — both driven by today's real pace,
not a historical multiplier.
+ long eta = Math.round(hintRemainingMs * (avgActualMs / globalHintAvg));
+
+ // If substantive tests are slower than history, raise remaining
toward scaled hints.
+ double robustScale = computeScale(observedVsCachedCompleted);
+ if (robustScale > 1.0) {
+ double shrink = completedCount / (double) (completedCount + 15);
+ double softenedScale = 1.0 + shrink * (robustScale - 1.0);
+ eta = Math.max(eta, Math.round(hintRemainingMs * softenedScale));
+ }
+
+ return Math.max(0L, eta);
}
/**
* How fast/slow this run is vs the historical cache for the same provider.
* {@code 1.0} = on pace; {@code >1} = slower than history; {@code <1} =
faster.
+ * <p>
+ * Pairs that look like assumes/skips (tiny observed, huge cached) are
ignored so they do not
+ * drag the scale to {@link #MIN_SCALE}.
*/
- static double computeScale(Collection<long[]> observedVsCachedCompleted) {
+ static double computeScale(Collection<TimingSample>
observedVsCachedCompleted) {
if (observedVsCachedCompleted == null ||
observedVsCachedCompleted.isEmpty()) {
return 1.0;
}
long observedSum = 0L;
long cachedSum = 0L;
- for (long[] pair : observedVsCachedCompleted) {
- if (pair == null || pair.length < 2) {
+ for (TimingSample sample : observedVsCachedCompleted) {
+ if (!isSubstantivePair(sample)) {
continue;
}
- if (pair[0] > 0L && pair[1] > 0L) {
- observedSum += pair[0];
- cachedSum += pair[1];
- }
+ observedSum += sample.observedMs();
+ cachedSum += sample.cachedMs();
}
if (cachedSum <= 0L || observedSum <= 0L) {
return 1.0;
@@ -233,29 +355,60 @@ final class TestTimingCache {
return scale;
}
+ /**
+ * {@code true} when the sample is usable for pace scaling (not an
assume/skip vs huge cache).
+ * See {@link #MAX_PAIR_SKEW} for why this is one-directional.
+ */
+ static boolean isSubstantivePair(TimingSample sample) {
+ if (sample == null) {
+ return false;
+ }
+ long observed = sample.observedMs();
+ long cached = sample.cachedMs();
+ if (observed < SUBSTANTIVE_OBSERVED_MS || cached <= 0L) {
+ return false;
+ }
+ double skew = cached / (double) observed;
+ return skew <= MAX_PAIR_SKEW;
+ }
+
+ private static double averagePositive(Collection<Long> values) {
+ return averageAtLeast(values, 1L);
+ }
+
+ /**
+ * Average of the values that are {@code >= minValue}, ignoring everything
else (missing,
+ * non-positive, or below the threshold). {@code 0.0} when nothing
qualifies.
+ */
+ private static double averageAtLeast(Collection<Long> values, long
minValue) {
+ if (values == null || values.isEmpty()) {
+ return 0.0;
+ }
+ long sum = 0L;
+ int count = 0;
+ for (Long value : values) {
+ if (value != null && value >= minValue) {
+ sum += value;
+ count++;
+ }
+ }
+ return count == 0 ? 0.0 : sum / (double) count;
+ }
+
private static double fallbackAverageMs(Collection<Long>
completedDurations,
Map<String, Long> cachedTimings,
long elapsedTimeMs) {
- if (completedDurations != null && !completedDurations.isEmpty()) {
- long sum = 0L;
- for (Long d : completedDurations) {
- if (d != null && d > 0L) {
- sum += d;
- }
- }
- return sum / (double) completedDurations.size();
+ double avg = averagePositive(completedDurations);
+ if (avg > 0.0) {
+ return avg;
}
- if (cachedTimings != null && !cachedTimings.isEmpty()) {
- long sum = 0L;
- for (Long d : cachedTimings.values()) {
- if (d != null && d > 0L) {
- sum += d;
- }
- }
- return sum / (double) cachedTimings.size();
+ avg = averagePositive(cachedTimings != null ? cachedTimings.values() :
null);
+ if (avg > 0.0) {
+ return avg;
}
- // Cold start: tiny placeholder so ETA is non-zero until the first
test finishes
- return elapsedTimeMs > 0L ? elapsedTimeMs : 30_000L;
+ // True cold start (no completions, no cache at all): a placeholder so
ETA is non-zero and
+ // visibly grows until the first test finishes, capped so a stalled
start can't balloon it.
+ return elapsedTimeMs > 0L ? Math.min(elapsedTimeMs,
COLD_START_PLACEHOLDER_CAP_MS) : 30_000L;
}
static Path cacheFile(String persistenceProvider) {
diff --git
a/itests/src/test/java/org/apache/unomi/itests/TestTimingCacheTest.java
b/itests/src/test/java/org/apache/unomi/itests/TestTimingCacheTest.java
index a5030fe19..11a4d48af 100644
--- a/itests/src/test/java/org/apache/unomi/itests/TestTimingCacheTest.java
+++ b/itests/src/test/java/org/apache/unomi/itests/TestTimingCacheTest.java
@@ -75,6 +75,48 @@ public class TestTimingCacheTest {
Assert.assertTrue(TestTimingCache.load("opensearch").isEmpty());
}
+ @Test
+ public void saveIgnoresSkipLikeDurationForNewKey() {
+ // A brand new key whose only observation so far is a near-instant
assume/skip must not create
+ // a cache entry at all — persisting it would seed the history with a
non-representative value.
+ TestTimingCache.save("elasticsearch",
Collections.singletonMap("SkipIT#skip", 50L));
+
Assert.assertNull(TestTimingCache.load("elasticsearch").get("SkipIT#skip"));
+ }
+
+ @Test
+ public void saveDoesNotErodeHistoryWithLaterSkipLikeDuration() {
+ // A test that's usually substantial (3000ms) but occasionally
short-circuits via an assume/skip
+ // (50ms) must keep its real historical average — the skip observation
must not be blended in.
+ TestTimingCache.save("elasticsearch",
Collections.singletonMap("FlakySkipIT#test", 3_000L));
+ Assert.assertEquals(Long.valueOf(3_000L),
TestTimingCache.load("elasticsearch").get("FlakySkipIT#test"));
+
+ TestTimingCache.save("elasticsearch",
Collections.singletonMap("FlakySkipIT#test", 50L));
+ Assert.assertEquals(Long.valueOf(3_000L),
TestTimingCache.load("elasticsearch").get("FlakySkipIT#test"));
+ }
+
+ @Test
+ public void saveStillSmoothsSubstantiveDurations() {
+ // Sanity check that the skip-filter didn't disable smoothing for
genuine observations.
+ TestTimingCache.save("elasticsearch",
Collections.singletonMap("SmoothedIT#test", 1_000L));
+ TestTimingCache.save("elasticsearch",
Collections.singletonMap("SmoothedIT#test", 2_000L));
+
+ // updated = 1000*(1-0.3) + 2000*0.3 = 1300
+ Assert.assertEquals(Long.valueOf(1_300L),
TestTimingCache.load("elasticsearch").get("SmoothedIT#test"));
+ }
+
+ @Test
+ public void saveOnlyPersistsSubstantiveEntriesFromMixedBatch() {
+ Map<String, Long> mixed = new HashMap<>();
+ mixed.put("HeavyIT#real", 5_000L);
+ mixed.put("SkipIT#skip", 10L);
+
+ TestTimingCache.save("elasticsearch", mixed);
+
+ Map<String, Long> loaded = TestTimingCache.load("elasticsearch");
+ Assert.assertEquals(Long.valueOf(5_000L), loaded.get("HeavyIT#real"));
+ Assert.assertNull(loaded.get("SkipIT#skip"));
+ }
+
@Test
public void computeScaleDefaultsToOneWithoutPairs() {
Assert.assertEquals(1.0,
TestTimingCache.computeScale(Collections.emptyList()), 0.0);
@@ -83,29 +125,239 @@ public class TestTimingCacheTest {
@Test
public void computeScaleUsesObservedOverCachedRatioAndClamps() {
- List<long[]> slower = Collections.singletonList(new long[]{2_000L,
1_000L});
+ List<TestTimingCache.TimingSample> slower =
+ Collections.singletonList(new
TestTimingCache.TimingSample(2_000L, 1_000L));
Assert.assertEquals(2.0, TestTimingCache.computeScale(slower), 0.0);
- List<long[]> tooFast = Collections.singletonList(new long[]{10L,
10_000L});
+ // Substantive but very fast vs cache → clamp to MIN_SCALE (not
ignored as assume-like)
+ List<TestTimingCache.TimingSample> tooFast =
+ Collections.singletonList(new
TestTimingCache.TimingSample(300L, 2_000L));
Assert.assertEquals(TestTimingCache.MIN_SCALE,
TestTimingCache.computeScale(tooFast), 0.0);
- List<long[]> tooSlow = Collections.singletonList(new long[]{50_000L,
1_000L});
+ // Substantive slowdown within skew guard → clamp to MAX_SCALE
+ List<TestTimingCache.TimingSample> tooSlow =
+ Collections.singletonList(new
TestTimingCache.TimingSample(15_000L, 1_000L));
Assert.assertEquals(TestTimingCache.MAX_SCALE,
TestTimingCache.computeScale(tooSlow), 0.0);
}
@Test
- public void estimateRemainingUsesScaledHistoryAndFallbackAverage() {
+ public void computeScaleIgnoresAssumeLikePairs() {
+ // 10ms observed vs 10s cached looks like a skip — must not drag scale
to MIN_SCALE.
+ List<TestTimingCache.TimingSample> skipPlusNormal = Arrays.asList(
+ new TestTimingCache.TimingSample(10L, 10_000L),
+ new TestTimingCache.TimingSample(2_000L, 2_000L));
+ Assert.assertEquals(1.0, TestTimingCache.computeScale(skipPlusNormal),
0.0);
+ }
+
+ @Test
+ public void computeScaleDoesNotIgnoreGenuineRegressions() {
+ // Historically fast (50ms) test now takes 25x longer (1_250ms): a
real regression, not a
+ // skip/assume artifact, so it must still count towards raising the
scale (clamped to MAX_SCALE
+ // since 25x exceeds it) rather than being filtered out by the skew
guard.
+ List<TestTimingCache.TimingSample> regressed =
+ Collections.singletonList(new
TestTimingCache.TimingSample(1_250L, 50L));
+ Assert.assertEquals(TestTimingCache.MAX_SCALE,
TestTimingCache.computeScale(regressed), 0.0);
+ }
+
+ @Test
+ public void estimateRemainingUsesLivePaceWithHistoricalHints() {
Map<String, Long> cached = new HashMap<>();
+ // Suite average historical = (1000+3000+2000)/3 = 2000
cached.put("A#a", 1_000L);
- cached.put("B#b", 2_000L);
+ cached.put("B#b", 3_000L);
+ cached.put("C#c", 2_000L);
- Set<String> remaining = new HashSet<>(Arrays.asList("A#a", "C#c"));
- List<long[]> observedVsCached = Collections.singletonList(new
long[]{1_500L, 1_000L});
- List<Long> completed = Collections.singletonList(1_500L);
+ // Completed A in 500ms wall; remaining B (heavier) and C (average).
+ Set<String> remaining = new HashSet<>(Arrays.asList("B#b", "C#c"));
+ List<TestTimingCache.TimingSample> observedVsCached =
+ Collections.singletonList(new
TestTimingCache.TimingSample(500L, 1_000L));
+ List<Long> completed = Collections.singletonList(500L);
+ long elapsed = 500L;
- // scale = 1.5 → A contributes 1500; C uncached → fallback avg 1500
- long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, 0L);
- Assert.assertEquals(3_000L, eta);
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, elapsed);
+
+ // rateEta = 2 * 500 = 1000
+ // hintShaped = (3000+2000) * (500/2000) = 1250 → heavier remaining
raises ETA
+ Assert.assertEquals(1_250L, eta);
+ }
+
+ @Test
+ public void
estimateRemainingLowersBelowFlatRateWhenRemainingIsHistoricallyLighter() {
+ // Suite average historical = (3000+500+500)/3 = 1333.33; remaining B
and C are both historically
+ // lighter than that average, so hint-shaped reweighting must lower
the ETA below the flat
+ // live-pace rate (remainingCount * avgActual = 2 * 1000 = 2000), not
just floor it there.
+ Map<String, Long> cached = new HashMap<>();
+ cached.put("A#a", 3_000L);
+ cached.put("B#b", 500L);
+ cached.put("C#c", 500L);
+
+ Set<String> remaining = new HashSet<>(Arrays.asList("B#b", "C#c"));
+ List<TestTimingCache.TimingSample> observedVsCached =
+ Collections.singletonList(new
TestTimingCache.TimingSample(1_000L, 3_000L));
+ List<Long> completed = Collections.singletonList(1_000L);
+ long elapsed = 1_000L;
+
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, elapsed);
+
+ // hintRemaining = 500+500 = 1000; eta = 1000 * (1000/1333.33) = 750,
well below the flat-rate 2000.
+ Assert.assertEquals(750L, eta);
+ long flatRateEta = Math.round(remaining.size() * 1_000.0);
+ Assert.assertTrue("hint-shaped ETA must be able to go below the flat
live-pace rate",
+ eta < flatRateEta);
+ }
+
+ @Test
+ public void
estimateRemainingTracksActualDurationAverageNotElapsedOverCount() {
+ // Elapsed wall time (300s) deliberately does NOT match completedCount
* avg duration (50*4s=200s)
+ // — e.g. time lost to setup/teardown between tests. A naive
elapsedTimeMs/completedCount pace
+ // (300_000/50 = 6_000ms/test) would overestimate the remaining 250
tests at 1_500_000ms; live
+ // pace must instead come from the actual completed-test durations
(avg 4_000ms/test).
+ Map<String, Long> cached = new HashMap<>();
+ for (int i = 0; i < 50; i++) {
+ cached.put("DoneIT#t" + i, 5_000L);
+ }
+ for (int i = 0; i < 250; i++) {
+ cached.put("TodoIT#t" + i, 5_000L);
+ }
+
+ Set<String> remaining = new HashSet<>();
+ for (int i = 0; i < 250; i++) {
+ remaining.add("TodoIT#t" + i);
+ }
+
+ List<TestTimingCache.TimingSample> observedVsCached = new
java.util.ArrayList<>();
+ List<Long> completed = new java.util.ArrayList<>();
+ for (int i = 0; i < 50; i++) {
+ observedVsCached.add(new TestTimingCache.TimingSample(4_000L,
5_000L));
+ completed.add(4_000L);
+ }
+ long elapsed = 300_000L;
+
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, elapsed);
+ // avgActual = 4_000 (from completedDurations, not elapsed/count);
globalHintAvg = 5_000;
+ // hintRemaining = 250*5_000 = 1_250_000; eta = 1_250_000 *
(4_000/5_000) = 1_000_000ms (~16.7m)
+ Assert.assertEquals(1_000_000L, eta);
+
+ // The naive elapsed/completedCount pace (6_000ms/test) would have
produced 1_500_000ms instead.
+ long naiveElapsedOverCountEta = Math.round(250 * (elapsed / (double)
completed.size()));
+ Assert.assertNotEquals(naiveElapsedOverCountEta, eta);
+ }
+
+ @Test
+ public void estimateRemainingUnaffectedByFailedTestWallTime() {
+ // ProgressListener never adds a failed/aborted test's duration to
completedDurations (see
+ // testFinished), but the suite-wide elapsed clock keeps advancing
regardless of outcome.
+ // The ETA must be driven by the one substantive success, not by
elapsed/completedCount
+ // (which would have been 50_200 / 1 = 50_200ms/test — a ~250x
inflation).
+ Map<String, Long> cached = new HashMap<>();
+ cached.put("FlakyIT#a", 200L);
+ cached.put("FlakyIT#b", 200L);
+
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("FlakyIT#b"));
+ List<Long> completed = Collections.singletonList(200L);
+ long elapsedIncludingFailures = 50_200L; // 10 failed tests @ 5s each
+ the 200ms success
+
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, cached, Collections.emptyList(), completed,
elapsedIncludingFailures);
+
+ Assert.assertEquals(200L, eta);
+ }
+
+ @Test
+ public void estimateRemainingIgnoresAssumeDilutionInLivePace() {
+ // 50 assume-like tests complete in ~50ms each (below
SUBSTANTIVE_OBSERVED_MS) before any of
+ // the 250 historically-heavy tests have run. The old
elapsed/completedCount pace would have
+ // been dragged down to ~50ms/test, collapsing the ETA for the heavy
tests still ahead.
+ Map<String, Long> cached = new HashMap<>();
+ for (int i = 0; i < 50; i++) {
+ cached.put("SkipIT#t" + i, 50L);
+ }
+ for (int i = 0; i < 250; i++) {
+ cached.put("HeavyIT#t" + i, 5_000L);
+ }
+
+ Set<String> remaining = new HashSet<>();
+ for (int i = 0; i < 250; i++) {
+ remaining.add("HeavyIT#t" + i);
+ }
+
+ List<Long> completed = new java.util.ArrayList<>();
+ for (int i = 0; i < 50; i++) {
+ completed.add(50L);
+ }
+ long elapsed = 50L * 50L;
+
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, cached, Collections.emptyList(), completed,
elapsed);
+
+ // No substantive completions yet → live pace falls back to the
historical average, so the
+ // heavy remaining tests are estimated at their full cached weight
(250 * 5_000 = 1_250_000),
+ // not diluted down toward the ~50ms/test pace of the skips seen so
far.
+ Assert.assertEquals(1_250_000L, eta);
+ }
+
+ @Test
+ public void
estimateRemainingAppliesSlowdownBoostWhenSubstantiveScaleExceedsOne() {
+ // A completed on the same key family as remaining R, but 4x slower
than its own cache entry —
+ // a genuine per-test regression that should raise the ETA above the
plain hint-shaped estimate.
+ Map<String, Long> cached = new HashMap<>();
+ cached.put("A#a", 50L);
+ cached.put("R#r", 1_000L);
+
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("R#r"));
+ List<TestTimingCache.TimingSample> observedVsCached =
+ Collections.singletonList(new
TestTimingCache.TimingSample(200L, 50L));
+ List<Long> completed = Collections.singletonList(200L);
+ long elapsed = 200L;
+
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, elapsed);
+
+ // Un-boosted hint-shaped estimate: 1000 * (200/525) ≈ 381
+ // robustScale = 200/50 = 4.0 (MAX_SCALE); shrink = 1/(1+15);
softenedScale = 1 + shrink*3 = 1.1875
+ // boosted estimate: 1000 * 1.1875 = 1187.5 → 1188, which wins over
the un-boosted 381
+ Assert.assertEquals(1_188L, eta);
+ }
+
+ @Test
+ public void
estimateRemainingSlowdownBoostRampApproachesRobustScaleAtLargeCompletedCount() {
+ // At a small completedCount the shrink ramp
(completedCount/(completedCount+15)) heavily damps
+ // the slowdown boost; at a large completedCount it should approach
the raw (interior, unclamped)
+ // robustScale instead of staying suppressed — exercising the ramp
away from the completedCount=1
+ // case covered by
estimateRemainingAppliesSlowdownBoostWhenSubstantiveScaleExceedsOne, and away
+ // from computeScale's own MIN_SCALE/MAX_SCALE clamp boundaries.
+ Map<String, Long> cached = new HashMap<>();
+ cached.put("A#a", 100L);
+ cached.put("R#r", 1_000L);
+
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("R#r"));
+ List<TestTimingCache.TimingSample> observedVsCached = new
java.util.ArrayList<>();
+ List<Long> completed = new java.util.ArrayList<>();
+ for (int i = 0; i < 100; i++) {
+ observedVsCached.add(new TestTimingCache.TimingSample(200L, 100L));
+ completed.add(200L);
+ }
+ long elapsed = 20_000L;
+
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
observedVsCached, completed, elapsed);
+
+ // robustScale = 200/100 = 2.0 (interior, not clamped); shrink =
100/115 ≈ 0.8696;
+ // softenedScale = 1 + 0.8696*(2.0-1.0) ≈ 1.8696; boosted =
1000*1.8696 ≈ 1870, which wins over
+ // the un-boosted hint-shaped estimate (1000 * 200/550 ≈ 364).
+ Assert.assertEquals(1_870L, eta);
+ }
+
+ @Test
+ public void estimateRemainingCapsColdStartPlaceholderForStalledStart() {
+ // No completions yet and no historical cache at all (e.g. the very
first-ever run stalls before
+ // its first success) — the per-remaining-test placeholder must not
grow unbounded with elapsed
+ // time; it should cap at COLD_START_PLACEHOLDER_CAP_MS rather than
ballooning towards hours.
+ Set<String> remaining = new HashSet<>(Arrays.asList("X#x", "Y#y",
"Z#z"));
+ long stalledElapsed = 500_000L; // 8+ minutes with nothing completed
and no cache
+
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, Collections.emptyMap(), Collections.emptyList(),
Collections.emptyList(), stalledElapsed);
+
+ Assert.assertEquals(3 * TestTimingCache.COLD_START_PLACEHOLDER_CAP_MS,
eta);
}
@Test
@@ -120,4 +372,105 @@ public class TestTimingCacheTest {
// avg of history = 2000
Assert.assertEquals(2_000L, eta);
}
+
+ @Test
+ public void estimateRemainingReturnsZeroForEmptyOrNullRemainingKeys() {
+ Map<String, Long> cached = Collections.singletonMap("A#a", 1_000L);
+ List<Long> completed = Collections.singletonList(500L);
+
+ Assert.assertEquals(0L, TestTimingCache.estimateRemainingMs(
+ Collections.emptySet(), cached, Collections.emptyList(),
completed, 500L));
+ Assert.assertEquals(0L, TestTimingCache.estimateRemainingMs(
+ null, cached, Collections.emptyList(), completed, 500L));
+ }
+
+ @Test
+ public void estimateRemainingHandlesNullCachedTimingsGracefully() {
+ // No historical cache at all (e.g. first-ever run, or an unreadable
cache file) — must not NPE
+ // and should fall back entirely to the in-run average.
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("X#x"));
+ List<Long> completed = Collections.singletonList(500L);
+
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, null, Collections.emptyList(), completed, 500L);
+
+ // fallbackAvg = avg(completed) = 500; no cache to weigh against, so
live pace and hint-shaped
+ // estimate both resolve to the plain average.
+ Assert.assertEquals(500L, eta);
+ }
+
+ @Test
+ public void estimateRemainingUsesFallbackAverageForUncachedRemainingKey() {
+ // "Cached#x" has a direct historical entry; "Uncached#y" does not and
must fall back to the
+ // average of the historical cache (not 0, and not just re-using
Cached#x's own value).
+ Map<String, Long> cached = new HashMap<>();
+ cached.put("Cached#x", 1_000L);
+ cached.put("Other#unrelated", 3_000L);
+
+ Set<String> remaining = new HashSet<>(Arrays.asList("Cached#x",
"Uncached#y"));
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, cached, Collections.emptyList(),
Collections.emptyList(), 0L);
+
+ // Cold start (nothing completed): hintRemainingMs =
cached("Cached#x")=1000
+ // + fallbackAvg(avg
of cache = 2000) = 3000
+ Assert.assertEquals(3_000L, eta);
+ }
+
+ @Test
+ public void estimateRemainingTreatsNonPositiveElapsedAsColdStart() {
+ // A negative/zero elapsed reading (e.g. clock oddity) must be treated
like cold start rather
+ // than feeding a nonsensical value into the live-pace division.
+ Map<String, Long> cached = Collections.singletonMap("X#x", 1_000L);
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("X#x"));
+ List<Long> completed = Collections.singletonList(500L);
+
+ long eta = TestTimingCache.estimateRemainingMs(remaining, cached,
Collections.emptyList(), completed, -100L);
+ Assert.assertEquals(1_000L, eta);
+ }
+
+ @Test
+ public void
estimateRemainingIgnoresSkipDurationWhenAveragingSubstantiveCompletions() {
+ // A mix of one assume-like completion (50ms) and one substantive
completion (3000ms) must
+ // average pace from the substantive one only (3000), not the diluted
blended average (1525).
+ Map<String, Long> cached = Collections.singletonMap("R#r", 1_000L);
+ Set<String> remaining = new
HashSet<>(Collections.singletonList("R#r"));
+ List<Long> completed = Arrays.asList(50L, 3_000L);
+
+ long eta = TestTimingCache.estimateRemainingMs(
+ remaining, cached, Collections.emptyList(), completed, 3_050L);
+
+ Assert.assertEquals(3_000L, eta);
+ }
+
+ @Test
+ public void isSubstantivePairBoundaryConditions() {
+ Assert.assertFalse(TestTimingCache.isSubstantivePair(null));
+
+ // Observed below SUBSTANTIVE_OBSERVED_MS → excluded regardless of
cached.
+ Assert.assertFalse(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(99L, 1_000L)));
+
+ // Observed exactly at the threshold → substantive (strict "<" check,
not "<=").
+ Assert.assertTrue(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(100L, 100L)));
+
+ // Non-positive cached → excluded regardless of observed.
+ Assert.assertFalse(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(1_000L, 0L)));
+
+ // Skew exactly at MAX_PAIR_SKEW → still substantive ("<=" boundary is
inclusive).
+ Assert.assertTrue(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(100L, 2_000L)));
+
+ // Skew just past MAX_PAIR_SKEW → excluded as assume/skip-like.
+ Assert.assertFalse(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(100L, 2_001L)));
+
+ // observed >> cached (a genuine regression, the opposite direction)
has no upper bound and is
+ // never excluded — this is the one-directional behavior the skew
guard is meant to have.
+ Assert.assertTrue(TestTimingCache.isSubstantivePair(new
TestTimingCache.TimingSample(1_000_000L, 1L)));
+ }
+
+ @Test
+ public void computeScaleToleratesNullSampleInCollection() {
+ List<TestTimingCache.TimingSample> withNull = Arrays.asList(
+ null,
+ new TestTimingCache.TimingSample(1_000L, 1_000L));
+ Assert.assertEquals(1.0, TestTimingCache.computeScale(withNull), 0.0);
+ }
}
