NOAA-OWP / wres

Code and scripts for the Water Resources Evaluation Service
Other
2 stars 1 forks source link

As a developer, I don't want an intermittent failure of a junit test #77

Open epag opened 4 weeks ago

epag commented 4 weeks ago

Author Name: James (James) Original Redmine Issue: 103804, https://vlab.noaa.gov/redmine/issues/103804 Original Date: 2022-04-15


Given a build sequence that includes junit unit tests When the @ProjectTest::testGetFeatureGroups@ runs Then it should always succeed

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-15T15:42:10Z


Got this just now, unconnected to any refactoring, so it is probably a real issue. Reporting the test standard out and the assertion error that failed. Will look into it later.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-15T15:43:18Z


Standard out attached.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-15T15:43:39Z


The assertion error:

ProjectTest > testGetFeatureGroups() FAILED
    org.opentest4j.AssertionFailedError at ProjectTest.java:172

org.opentest4j.AssertionFailedError: expected: <[FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]]]> but was: <[FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]]]>
    at org.junit.jupiter.api.AssertionUtils.fail(AssertionUtils.java:55)
    at org.junit.jupiter.api.AssertionUtils.failNotEqual(AssertionUtils.java:62)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:182)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:177)
    at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:1141)
    at wres.io.project.ProjectTest.testGetFeatureGroups(ProjectTest.java:172)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725)
    at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
    at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
    at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
    at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
    at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:214)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:210)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:135)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:66)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)
    at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:99)
    at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:79)
    at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:75)
    at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
    at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
    at com.sun.proxy.$Proxy5.stop(Unknown Source)
    at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:133)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)
    at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)
    at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:414)
    at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
    at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
    at java.base/java.lang.Thread.run(Thread.java:829)
epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-15T15:48:11Z


The expected:

FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=]]]]>

The actual:

FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=]]], FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=]]]]>

They are each contained in a @Set@, so order doesn't matter.

On first glance, I see no difference, so there must be some underlying difference that is not part of the string representation. Sigh.

When attempting to reproduce, try the @@RepeatedTest@ feature of junit5 and include the full state in the strings.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:06:33Z


Just occurred on the build server:

https://vlab.noaa.gov/jenkins/job/Verify_OWP_WRES/4373/

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:08:13Z


https://vlab.noaa.gov/jenkins/job/Verify_OWP_WRES/4374 which I started manually with no code changes is underway.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:11:31Z


It failed again.

There are some other techniques for comparing sets in other tests, I am looking them up to see if those might help.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:15:30Z


It is an intermittent one for sure, although it's interesting it happened twice in a row. I would start with @@RepeatedTest@ to see whether it can be reproduced consistently.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:18:53Z


I will take a look at this one too, see whether it can be reproduced consistently.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:22:14Z


The code I was thinking of is in systests Scenario703:


    @Test
    public void testScenario()
    {
        Set<Path> pathsWritten = ScenarioHelper.executeScenario( scenarioInfo );
        Set<Path> actualFileNamesThatExist = pathsWritten.stream()
                                                         .filter( Files::exists )
                                                         .map( Path::getFileName )
                                                         .collect( Collectors.toSet() );
        Set<Path> netcdfFilesThatExist =
                actualFileNamesThatExist.stream()
                                        .filter( p -> p.toString()
                                                       .endsWith( ".nc" ) )
                                        .collect( Collectors.toSet() );
        Set<Path> csvFilesThatExist =
                actualFileNamesThatExist.stream()
                                        .filter( p -> p.toString()
                                                       .endsWith( ".csv" ) )
                                        .collect( Collectors.toSet() );
        assertEquals( "The actual set of netCDF file names does not match the expected set of file names."
                      + " These existed in expected, but not in actual: "
                      + Sets.difference( EXPECTED_NC_FILES, netcdfFilesThatExist )
                      + " while these existed in actual, but not expected: "
                      + Sets.difference( netcdfFilesThatExist, EXPECTED_NC_FILES ),
                      EXPECTED_NC_FILES,
                      netcdfFilesThatExist );

        // Because NWIS adds and removes sites in this set every so often, this
        // test will do broad-strokes assertions rather than precise ones. The
        // correctness of each WRES component involved is handled elsewhere.
        int countOfCsvFiles = csvFilesThatExist.size();
        assertTrue( "The count of CSV files was expected to be above "
                    + EXPECTED_AT_LEAST_THIS_MANY_CSV_FILES + " but was "
                    + countOfCsvFiles,
                    countOfCsvFiles > EXPECTED_AT_LEAST_THIS_MANY_CSV_FILES );
        assertTrue( "The count of non-pairs CSV files was expected to be divisible by 8 but was not: "
                    + ( countOfCsvFiles - 1 ),
                    ( countOfCsvFiles - 1 ) % 8 == 0 );
        LOGGER.info( "########################################################## COMPLETED "
                     + this.getClass().getSimpleName().toLowerCase()
                     + NEWLINE );
    }
</code>

The use of @Sets.difference()@ is in the error message. The assertion is simply @assertEquals@.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:23:38Z


Which assertEquals? Ah: @import static org.junit.Assert.assertEquals;@

That is the venerable JUnit method, not the jupiter method.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:25:00Z


More importantly, let's examine the two lines more closely.

expected:  java.util.ImmutableCollections$SetN@3ae05454<[FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]]]>
but was: java.util.Collections$UnmodifiableSet@6ebcbec1<[FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]]]>
epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:26:27Z


The only difference I see is right there at the start: the classes implementing @Set@.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:27:02Z


Well, this does not bode extremely well.

!500_tries.png!

That said, this isn't exactly reproducing because there are some static set-up and tear-down methods (edit: hence the timing for iteration 1 versus the rest), so perhaps this really counts as "1" for the purposes of reproducing, not 500.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:28:54Z


Although it is only this. Hmmm.

    @BeforeAll
    static void oneTimeSetup()
    {
        // Set the JVM timezone for use by H2. Needs to happen before anything else
        TimeZone.setDefault( TimeZone.getTimeZone( "UTC" ) );
    }

</code>

But perhaps @@RepeatedTest@ does not repeat the @@BeforeEach@ and @@AfterEach@. edit: the timings suggests not.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:31:41Z


James wrote:

But perhaps @@RepeatedTest@ does not repeat the @@BeforeEach@ and @@AfterEach@. edit: the timings suggests not.

Well, not according to this:

https://www.baeldung.com/junit-5-repeated-test

edit: @"Each execution of the @RepeatedTest will behave like a regular @Test having full JUnit test life cycle support. Meaning that, during each execution, the @BeforeEach and @AfterEach methods will be called."@

Perhaps the timings is just a warm-up thing, one jvm for all instances.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:38:15Z


I did a @../gradlew clean check@ in @wres-io@ and kind of sort of reproduced it:

289 tests completed, 1 failed, 12 skipped
testsuite wres.io.geography.wrds.v2.WRDSLocationRootDocumentTest:
  testcase wres.io.project.ProjectTest > testGetFeatureGroups(): org.opentest4j.AssertionFailedError: expected: <[FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]]]> but was: <[FeatureGroup[name=F-F,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=G-G,features=[FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]], FeatureGroup[name=A feature group!,features=[FeatureTuple[left=FeatureKey[name=F,description=,srid=0,wkt=],right=FeatureKey[name=F,description=,srid=0,wkt=],baseline=<null>], FeatureTuple[left=FeatureKey[name=G,description=,srid=0,wkt=],right=FeatureKey[name=G,description=,srid=0,wkt=],baseline=<null>]]]]>
    at org.junit.jupiter.api.AssertionUtils.fail(AssertionUtils.java:55)
    at org.junit.jupiter.api.AssertionUtils.failNotEqual(AssertionUtils.java:62)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:182)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:177)
    at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:1141)
    at wres.io.project.ProjectTest.testGetFeatureGroups(ProjectTest.java:172)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725)
    ...

> Task :wres-io:test FAILED

Why is it running @testcase wres.io.project.ProjectTest > testGetFeatureGroups()@ under both @testsuite wres.io.geography.wrds.v2.WRDSLocationRootDocumentTest@ and under @testsuite wres.io.writing.commaseparated.statistics.CommaSeparatedScoreWriterTest:@?

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:40:06Z


junit tests run in a deterministic, if unpredictable, order by default, so test order variations that might hint at test isolation issues is probably not the cause, plus the set-up occurs for each test separately.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:42:46Z


Jesse wrote:

Why is it running @testcase wres.io.project.ProjectTest > testGetFeatureGroups()@ under both @testsuite wres.io.geography.wrds.v2.WRDSLocationRootDocumentTest@ and under @testsuite wres.io.writing.commaseparated.statistics.CommaSeparatedScoreWriterTest:@?

Isn't that just a weird printing issue? Note that one is a @testsuite@, the other a @testcase@ (edit: oh, you already noted that, I misread). It might be something, though.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:46:29Z


Perhaps a concurrency issue with H2? They should be separate database instances.

Ah, this could be it, in @ProjectTest@ the database name might be the same as another test:

    @BeforeEach
    void RunBeforeEachTest() throws SQLException, LiquibaseException
    {
        MockitoAnnotations.openMocks( this );

        // Create the database and connection pool
        this.testDatabase = new TestDatabase( "SingleValuedForecastRetrieverTest" );
</code>
epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:47:29Z


I see four tests using that same H2 database named "SingleValuedForecastRetrieverTest", so that could be it.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:49:31Z


I think junit tests run sequentially, by default, not concurrently(?) Plus the set-up happens for each test iteration, separately.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:51:32Z


Also, we use that same approach in a bunch of places, so I doubt that is the issue. If you look at the failing test, the string representation of the (edit: content of the) assertion does not point to any differences. To me, that suggests that something is missing from the string representation that is rendering the two seemingly equal things unequal. Or perhaps there is a hashcode/equals/compareTo issue somewhere.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:52:21Z


I replaced those four with @this.getClass().getName()@ instead.

@DetailsTest@ has it this way, because each test might run in parallel: @ this.testDatabase = new TestDatabase( "DetailsTest" + random.nextLong() );@

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:53:44Z


There is no harm in doing that, I think it is a good change to make, but I doubt it is the issue.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:53:49Z


James wrote:

I think junit tests run sequentially, by default, not concurrently(?) Plus the set-up happens for each test iteration, separately.

I hope they run concurrently. If not, that is an opportunity for speedup.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T15:56:38Z


You are probably right. I undid the change, did another @clean test@ in @wres-io@ and it did not reproduce the issue.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:56:51Z


Jesse wrote:

James wrote:

I think junit tests run sequentially, by default, not concurrently(?) Plus the set-up happens for each test iteration, separately.

I hope they run concurrently. If not, that is an opportunity for speedup.

I am pretty sure they do not. I think there is a junit5 parameter and annotation to make it so, but we don't use it. But it would be interesting to do this as it may point to a bunch of test isolation issues. I could be wrong, but that is my recollection re: the special parameter/annotation.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T15:58:43Z


https://stackoverflow.com/questions/50586201/parallel-test-case-execution-with-junit-5

edit: and following the link to the canonical source:

https://junit.org/junit5/docs/snapshot/user-guide/#writing-tests-parallel-execution

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T16:02:09Z


We will have to try that at some point. I bet it finds a bunch of test isolation issues... (edit: I hope it doesn't, of course, but I think you already spotted one).

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T16:05:54Z


There are (at least) two kinds of concurrent test execution, though:

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T16:06:17Z


The test for equality of two @FeatureGroup@ defers to the @GeometryGroup@ it wraps. The state of that last thing is this:

syntax = "proto3";

package wres.statistics.generated;

import "wresproto/geometry_tuple.proto";

option java_package = "wres.statistics.generated";
option java_outer_classname = "GeometryGroupProto";
option java_multiple_files = true;

message GeometryGroup
{
    // A group of geometries associated with an evaluation.

    repeated GeometryTuple geometry_tuples = 1;
    // Zero or more geometry tuples.

    string region_name = 2;
    // The name of the spatial aggregation or geographic region associated with 
    // the geometries (e.g., Patagonia).
}
syntax = "proto3";

package wres.statistics.generated;

import "wresproto/geometry.proto";

option java_package = "wres.statistics.generated";
option java_outer_classname = "GeometryTupleProto";
option java_multiple_files = true;

message GeometryTuple
{
    /*A tuple of geometries for each dataset associated with an evaluation.
     An evaluation may contain a separate geometry for each of the left, 
     right and baseline data and, in future, possibly the climatological 
     data too. If only one geometry is present, it is assumed to apply 
     to all datasets.*/

    Geometry left = 1;
    // Geometry for the left-sided data.

    Geometry right = 2;
    // Geometry for the right-sided data.

    Geometry baseline = 3;
    // Geometry for the baseline-sided data.
}
syntax = "proto3";

package wres.statistics.generated;

option java_package = "wres.statistics.generated";
option java_outer_classname = "GeometryProto";
option java_multiple_files = true;

message Geometry
{
    /*Elementary representation of a geometry with a spatial reference 
     identifier (srid) and well-known text (wkt) string.*/

    string wkt = 1;
    // Geometry string.

    int32 srid = 2;
    // Coordinate system.

    string name = 3;
    /*User-friendly name for all sides of a pairing or the left side only if 
    other sides are defined explicitly. (e.g., DRRC2).*/

    string description = 4;
    // User-friendly description of the geometry.
}

All of that stuff appears to be in the string representation of the failed assertion. Hmmm.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T16:07:04Z


Jesse wrote:

There are (at least) two kinds of concurrent test execution, though:

  • Concurrent across classes (e.g. class A simultaneous with class B), and
  • Concurrent within classes (e.g. test 1 within class A simultaneous with test 2 within class A).

That is true, but I think it is sequential in both respects - but I could be wrong about that.

edit: but from the documentation I linked:

test classes and methods will still be executed sequentially by default.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T16:08:30Z


commit:7b4bb71f14fe988e30aad8e17bde8e3a42ee3d24 allows for concurrent test class execution, it doesn't address concurrent test execution within one class. A pseudo-random number would be needed, like @wres.io.data.details.DetailsTest@ does it.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T16:20:41Z


Hmmm, I cannot see anything obvious. The state being compared is the state we see in the failed assertion and the state we see in the failed assertion is seemingly identical state. The order will make no difference, the set implementation will make no difference. edit: I mean #103804-4.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T18:49:02Z


No closer.

Any check for equality on the @GeometryGroup@ imposes an ordering, as hinted at here:

    /**
     * Creates a geometry group from the input.
     * 
     * @param name the group name, optional
     * @param features the features, required
     * @return the geometry tuple
     * @throws NullPointerException if the features are null
     */

    public static GeometryGroup getGeometryGroup( String name, Set<FeatureTuple> features )
    {
        Objects.requireNonNull( features );

        // Use a predictable order because the GeometryGroup contains a list
        List<FeatureTuple> sorted = new ArrayList<>( new TreeSet<>( features ) );
        List<GeometryTuple> geometries = sorted.stream()
                                               .map( FeatureTuple::getGeometryTuple )
                                               .collect( Collectors.toList() );

        GeometryGroup.Builder builder = GeometryGroup.newBuilder()
                                                     .addAllGeometryTuples( geometries );

        if ( Objects.nonNull( name ) )
        {
            builder.setRegionName( name );
        }

        return builder.build();
    }
</code>

But that concerns the order of @GeometryTuple@ within the @GeometryGroup@, not the order of @GeometryTuple@ within a @Set@, which is unordered. As we can see from #103804-4, there is no issue with the order of tuples within the group that contains two tuples.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T18:54:46Z


The @FeatureGroupTest@ covers the corners of @equals@, @hashCode@ and @compareTo@ of the @FeatureGroup@, AFAICT.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T18:58:00Z


The @MessageFactoryTest@ could probably do with a test of the @getGeometryGroup@ that asserts the order invariance of the output w/r to the input, but this is just rearranging deckchairs and not helping with the root cause.

epag commented 4 weeks ago

Original Redmine Comment Author Name: Jesse (Jesse) Original Date: 2022-04-26T18:59:59Z


I had bumped the priority to @Immediate@ only because the builds were failing. At this point I think it's on the back burner again, especially if nothing obvious is visible.

Were you able to reproduce locally ever?

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T19:13:51Z


No, unable to reproduce, either by running repeatedly or using the @@RepeatedTest@ annotation in junit5. My assumption, based on reading, is that @@RepeatedTest@ runs in exactly the same way as @@Test@, repeatedly, and yet I cannot reproduce even with a high number of repetitions.

It is both puzzling and troubling. I think it is unrelated to ## The assertion failure stands alone. It clearly states that two sets with seemingly equal content are unequal and the string representation of the content seems to be complete. I think this is a hard bug, possibly related to an inconsistency between equals/hashcode/compareTo (which nevertheless seems to be cornered by unit tests), or something else I am missing. Again, troubling.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T19:18:02Z


I mean, it could also be an issue with the java protobuf bindings and the way they test for equality, but I highly doubt it, else we'd probably have seen this issue elsewhere.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T22:43:32Z


No joy. This is a hard one to reproduce and hence to diagnose. I've added a few assertions in commit:wres|8258b46a377335aefe993c0503ab87ff89e85c7e to help clarify which of the @FeatureGroup@ within the @Set@ is failing the equality check, but I doubt that will push things forward very much when it does reoccur.

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T22:47:14Z


Actually, I will add those to an @assertAll@ so we get details for any/all failures at once...

epag commented 4 weeks ago

Original Redmine Comment Author Name: James (James) Original Date: 2022-04-26T22:49:11Z


James wrote:

Actually, I will add those to an @assertAll@ so we get details for any/all failures at once...

commit:wres|d45a905848ae3559034803accccf458b6889fb2d.