UNOMI-970: Fix IT ProgressListener ETA using live suite pace

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
 

itests/src/test/java/org/apache/unomi/itests/ProgressListener.java

@@ -28,6 +28,7 @@
 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 @@
  *   <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 @@ private static class TestTime {
      * 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 @@ private static class TestTime {
     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 void testRunStarted(Description description) {
     @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 void testFinished(Description description) {
         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 void testFinished(Description description) {
         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 void testIgnored(Description description) {
         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 @@ private String escapeCsv(String value) {
     }
 
     /**
-     * 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 @@ private long estimateRemainingTime(int completed, long elapsedTime) {
                 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 @@ private void displayProgress() {
         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);
 

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"));
+    }
+}