Incorrect test reports on CI

[findepi]

For example two lines from https://github.com/trinodb/trino/actions/runs/7165229118/job/19506975076?pr=20059

[INFO] Running io.trino.operator.aggregation.TestTypedHistogram
Error:  Tests run: 32, Failures: 4, Errors: 0, Skipped: 0, Time elapsed: 3.458 s <<< FAILURE! -- in io.trino.operator.aggregation.TestTypedHistogram

Tests run: 32, Failures: 4 -- but the TestTypedHistogram class has only one test method.

[findepi]

cc @trinodb/maintainers

[findepi]

I assume contributors rely on test reports to know which tests they need to re-run locally when fixing the PR. Wonder how can we make test reports reliable.

[losipiuk]

Surefire issue: https://issues.apache.org/jira/browse/SUREFIRE-2217

[martint]

I understand that the numbers are incorrect, but is the reported failed test correct? I.e, is the exception attributed to the right test? If so, I think that’s enough to be able to tell which test is broken. The numbers being wrong is just a minor annoyance. It will get fixed when that surefire bug gets fixed.

[losipiuk]

I understand that the numbers are incorrect, but is the reported failed test correct? I.e, is the exception attributed to the right test? If so, I think that’s enough to be able to tell which test is broken. The numbers being wrong is just a minor annoyance. It will get fixed when that surefire bug gets fixed.

There is some misleading information in the output - e.g. reported failing tests may be grouped nonsensically. But it looks like individual failing tests are reported correctly.

E.g. here TestSurefireX and TestSurefireY share base class and are setup so test methods in TestSurefireX fail.

-------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
2023-12-14T09:56:38.078-0600    INFO    ForkJoinPool-1-worker-1 io.airlift.log.Logging  Logging to stderr
[INFO] Running io.trino.abc.TestSurefireY
[INFO] Running io.trino.abc.TestSurefireX
[ERROR] Tests run: 7, Failures: 3, Errors: 0, Skipped: 0, Time elapsed: 1.028 s <<< FAILURE! -- in io.trino.abc.TestSurefireY
[ERROR] io.trino.abc.TestSurefireX.testA -- Time elapsed: 0.256 s <<< FAILURE!
org.opentest4j.AssertionFailedError: expected: <false> but was: <true>
        at io.trino.abc.TestSurefireBase.testA(TestSurefireBase.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

[ERROR] io.trino.abc.TestSurefireX.testB -- Time elapsed: 0.483 s <<< FAILURE!
org.opentest4j.AssertionFailedError: expected: <false> but was: <true>
        at io.trino.abc.TestSurefireBase.testB(TestSurefireBase.java:53)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

[ERROR] io.trino.abc.TestSurefireX.testC -- Time elapsed: 0.510 s <<< FAILURE!
org.opentest4j.AssertionFailedError: expected: <false> but was: <true>
        at io.trino.abc.TestSurefireBase.testC(TestSurefireBase.java:63)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 2.012 s <<< FAILURE! -- in io.trino.abc.TestSurefireX
[ERROR] io.trino.abc.TestSurefireX.testD -- Time elapsed: 1.990 s <<< FAILURE!
org.opentest4j.AssertionFailedError: expected: <false> but was: <true>
        at io.trino.abc.TestSurefireBase.testD(TestSurefireBase.java:73)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

[INFO]
[INFO] Results:
[INFO]
[ERROR] Failures:
[ERROR]   TestSurefireX>TestSurefireBase.testA:43 expected: <false> but was: <true>
[ERROR]   TestSurefireX>TestSurefireBase.testB:53 expected: <false> but was: <true>
[ERROR]   TestSurefireX>TestSurefireBase.testC:63 expected: <false> but was: <true>
[ERROR]   TestSurefireX>TestSurefireBase.testD:73 expected: <false> but was: <true>
[INFO]

[findepi]

I understand that the numbers are incorrect, but is the reported failed test correct? I.e, is the exception attributed to the right test?

yes, seems so

If so, I think that’s enough to be able to tell which test is broken

well, the example log clearly says that TestTypedHistogram failed, but it doesn't say how it failed.
i would expect contributors will get confused about that, but maybe they will just overlook that line?
I noticed the line because i searched for <<< to find failing tests in the build output.

[findepi]

in https://github.com/trinodb/trino/actions/runs/7287026131/job/19856994898?pr=20194
when i see the summary

Error:  Errors: 
Error:    TestRaptorStorageManager.tearDown:167 » FileSystem /tmp/4993829403019729919: failed to delete one or more files; see suppressed exceptions for details
[INFO] 
Error:  Tests run: 1029, Failures: 0, Errors: 1, Skipped: 162

i assume that only the tearDown failed (Failures: 0, Errors: 1)
however, only when grepping the log i can see that there was one more failure (reported as TestRaptorStorageManager.testWriterRollback)