Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

quarkus-junit5: Running non-Quarkus unit-tests in parallel fails #24524

Closed
calohmn opened this issue Mar 24, 2022 · 3 comments · Fixed by #24548
Closed

quarkus-junit5: Running non-Quarkus unit-tests in parallel fails #24524

calohmn opened this issue Mar 24, 2022 · 3 comments · Fixed by #24548
Assignees
Labels
area/testing kind/bug Something isn't working
Milestone

Comments

@calohmn
Copy link

calohmn commented Mar 24, 2022

Describe the bug

As I understood it, the fix for #7696 should have made it possible to properly configure unit-test log output also for plain unit tests without @QuarkusTest.

I have a Maven module with a quarkus-core dependency and plain, Quarkus-independent unit tests.
I've added the quarkus-junit5 dependency and configured logging via an application.yaml in the test resources folder.
All is running as expected when running the tests one after the other.

But, when running the tests in parallel, via a maven surefire config with

junit.jupiter.execution.parallel.enabled = true
junit.jupiter.execution.parallel.mode.default = same_thread
junit.jupiter.execution.parallel.mode.classes.default = concurrent

, the test execution fails with

java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
	at io.smallrye.config.SmallRyeConfigProviderResolver.registerConfig(SmallRyeConfigProviderResolver.java:118)
	at io.quarkus.test.junit.BasicLoggingEnabler.beforeAll(BasicLoggingEnabler.java:102)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeBeforeAllCallbacks$10(ClassBasedTestDescriptor.java:381)

.

See the complete, verbose log output
[INFO] Running org.eclipse.hono.service.management.tenant.TrustedCertificateAuthorityTest
[INFO] Running org.eclipse.hono.deviceregistry.service.credentials.AbstractCredentialsServiceTest
[INFO] Running org.eclipse.hono.deviceregistry.service.device.AbstractDeviceManagementServiceTest
[INFO] Running org.eclipse.hono.deviceregistry.service.credentials.AbstractCredentialsManagementServiceTest
BasicLoggingEnabler took 137 ms from static init to start of beforeAll()
BasicLoggingEnabler took 138 ms from static init to start of beforeAll()
BasicLoggingEnabler took 138 ms from static init to start of beforeAll()
BasicLoggingEnabler took 138 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.deviceregistry.service.device.AbstractRegistrationServiceTest
BasicLoggingEnabler took 209 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.deviceregistry.service.device.EdgeDeviceAutoProvisionerTest
BasicLoggingEnabler took 210 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.deviceregistry.service.tenant.AbstractTenantManagementServiceTest
BasicLoggingEnabler took 220 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.deviceregistry.service.tenant.DefaultTenantInformationServiceTest
BasicLoggingEnabler took 263 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.deviceregistry.util.DeviceRegistryUtilsTest
BasicLoggingEnabler took 298 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.FilterTest
[INFO] Running org.eclipse.hono.service.management.SortTest
BasicLoggingEnabler took 343 ms from static init to start of beforeAll()
BasicLoggingEnabler took 346 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.CommonSecretTest
BasicLoggingEnabler took 359 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.CredentialsDtoTest
BasicLoggingEnabler took 374 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.CredentialsTest
BasicLoggingEnabler took 398 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.GenericSecretTest
BasicLoggingEnabler took 437 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.PasswordSecretTest
BasicLoggingEnabler took 448 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.PskSecretTest
BasicLoggingEnabler took 470 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.credentials.X509CertificateSecretTest
BasicLoggingEnabler took 476 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.device.DelegatingDeviceManagementHttpEndpointTest
BasicLoggingEnabler took 497 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.device.DeviceAndGatewayAutoProvisionerTest
BasicLoggingEnabler took 502 ms from static init to start of beforeAll()
[INFO] Running org.eclipse.hono.service.management.device.DeviceTest
BasicLoggingEnabler took 541 ms from static init to start of beforeAll()
BasicLoggingEnabler took 554 ms to load config
[INFO] Running org.eclipse.hono.service.management.tenant.TenantTest
BasicLoggingEnabler took 566 ms from static init to start of beforeAll()
BasicLoggingEnabler ConfigSource: SysPropConfigSource
BasicLoggingEnabler ConfigSource: EnvConfigSource
BasicLoggingEnabler ConfigSource: PropertiesConfigSource[source=jar:file:///home/cal/.m2/repository/org/eclipse/hono/hono-service-base/2.0.0-SNAPSHOT/hono-service-base-2.0.0-SNAPSHOT.jar!/application.properties]
BasicLoggingEnabler ConfigSource: io.quarkus.test.common.http.TestHTTPConfigSourceProvider$TestURLConfigSource@2397d752
BasicLoggingEnabler ConfigSource: PropertiesConfigSource[source=Runtime Defaults]
BasicLoggingEnabler ConfigSource: DefaultValuesConfigSource
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
BasicLoggingEnabler is swapping config after java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.132 s <<< FAILURE! - in org.eclipse.hono.deviceregistry.service.credentials.AbstractCredentialsServiceTest
[ERROR] org.eclipse.hono.deviceregistry.service.credentials.AbstractCredentialsServiceTest  Time elapsed: 0.13 s  <<< ERROR!
java.lang.IllegalStateException: SRCFG00017: Configuration already registered for the given class loader
	at io.smallrye.config.SmallRyeConfigProviderResolver.registerConfig(SmallRyeConfigProviderResolver.java:118)
	at io.quarkus.test.junit.BasicLoggingEnabler.beforeAll(BasicLoggingEnabler.java:102)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeBeforeAllCallbacks$10(ClassBasedTestDescriptor.java:381)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.invokeBeforeAllCallbacks(ClassBasedTestDescriptor.java:381)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:205)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:80)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:148)
	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.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185)
	at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

BasicLoggingEnabler took 443 ms from start of beforeAll() to end
BasicLoggingEnabler took 315 ms from start of beforeAll() to end
BasicLoggingEnabler took 744 ms from start of beforeAll() to end
BasicLoggingEnabler took 522 ms from start of beforeAll() to end
BasicLoggingEnabler took 433 ms from start of beforeAll() to end
BasicLoggingEnabler took 671 ms from start of beforeAll() to end
BasicLoggingEnabler took 406 ms from start of beforeAll() to end
BasicLoggingEnabler took 342 ms from start of beforeAll() to end
BasicLoggingEnabler took 537 ms from start of beforeAll() to end
BasicLoggingEnabler took 410 ms from start of beforeAll() to end
BasicLoggingEnabler took 383 ms from start of beforeAll() to end
BasicLoggingEnabler took 660 ms from start of beforeAll() to end
BasicLoggingEnabler took 742 ms from start of beforeAll() to end
BasicLoggingEnabler took 482 ms from start of beforeAll() to end
BasicLoggingEnabler took 742 ms from start of beforeAll() to end
BasicLoggingEnabler took 506 ms from start of beforeAll() to end
BasicLoggingEnabler took 554 ms from start of beforeAll() to end
BasicLoggingEnabler took 621 ms from start of beforeAll() to end
BasicLoggingEnabler took 675 ms from start of beforeAll() to end
BasicLoggingEnabler took 583 ms from start of beforeAll() to end
BasicLoggingEnabler took 379 ms from start of beforeAll() to end

Expected behavior

Unit tests can be run in parallel - at least the non @QuarkusTest ones.

Actual behavior

Tests fail with an SRCFG00017: Configuration already registered for the given class loader exception.

How to Reproduce?

Take a Quarkus-independent Maven module containing at least 10 unit test classes, configured to be run in parallel (e.g. with

  <build>
    <plugins>
      <plugin>
        <groupId>org.apache.maven.plugins</groupId>
        <artifactId>maven-surefire-plugin</artifactId>
        <configuration>
          <properties>
            <!-- execute top-level classes in parallel but methods in same thread -->
            <configurationParameters>
              junit.jupiter.execution.parallel.enabled = true
              junit.jupiter.execution.parallel.mode.default = same_thread
              junit.jupiter.execution.parallel.mode.classes.default = concurrent
            </configurationParameters>
          </properties>
          <systemProperties>
            <io.quarkus.test.junit.BasicLoggingEnabler.verbose>true</io.quarkus.test.junit.BasicLoggingEnabler.verbose>
          </systemProperties>
        </configuration>
      </plugin>
    </plugins>
  </build>

) and add the

    <dependency>
      <groupId>io.quarkus</groupId>
      <artifactId>quarkus-junit5</artifactId>
      <scope>test</scope>
    </dependency>

dependency.
Run the tests via maven.

Output of uname -a or ver

Linux 5.4.0-105-generic #119-Ubuntu SMP Mon Mar 7 18:49:24 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk version "17.0.2" 2022-01-18 
OpenJDK Runtime Environment Temurin-17.0.2+8 (build 17.0.2+8) 
OpenJDK 64-Bit Server VM Temurin-17.0.2+8 (build 17.0.2+8, mixed mode, sharing)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.7.3

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.8.5

Additional information

No response

@quarkus-bot
Copy link

quarkus-bot bot commented Mar 24, 2022

/cc @geoand

@famod famod self-assigned this Mar 24, 2022
@famod
Copy link
Member

famod commented Mar 24, 2022

Thanks for reporting, will have a look ASAP.

calohmn added a commit to bosch-io/hono that referenced this issue Mar 24, 2022
…e modules.

Otherwise there are errors thrown by the quarkus-junit5 BasicLoggingEnabler
(see quarkusio/quarkus#24524).

Signed-off-by: Carsten Lohmann <carsten.lohmann@bosch.io>
@famod
Copy link
Member

famod commented Mar 25, 2022

#24548 will fix this issue.
All tests will have to wait until the first test that entered the method of BasicLoggingEnabler is done.
This makes more sense IMO than letting them all advance far into the method until setting the config, because logging activation is only needed once (statically), not per test thread.

calohmn added a commit to eclipse-hono/hono that referenced this issue Mar 25, 2022
Otherwise there are errors thrown by the quarkus-junit5 BasicLoggingEnabler
(see quarkusio/quarkus#24524).

Signed-off-by: Carsten Lohmann <carsten.lohmann@bosch.io>
@quarkus-bot quarkus-bot bot added this to the 2.9 - main milestone Mar 25, 2022
@gsmet gsmet modified the milestones: 2.9 - main, 2.8.0.Final Mar 28, 2022
@gsmet gsmet modified the milestones: 2.8.0.Final, 2.7.6.Final May 5, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/testing kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants