jqwik icon indicating copy to clipboard operation
jqwik copied to clipboard

Allow parallel test runs with SBT

Open SimY4 opened this issue 2 years ago • 15 comments

Testing Problem

Getting this error quite frequently. Not sure why. Running tests from SBT, nothing was updated recently except SBT itself.

Test com.github.simy4.coregex.jqwik.CoregexArbitraryProviderTest.shouldGenerateAnyString failed: java.util.ConcurrentModificationException: null, took 0.044s
[error]     at java.util.HashMap.computeIfAbsent(HashMap.java:1221)
[error]     at net.jqwik.engine.execution.lifecycle.StoreRepository.addStore(StoreRepository.java:56)
[error]     at net.jqwik.engine.execution.lifecycle.StoreRepository.create(StoreRepository.java:51)
[error]     at net.jqwik.engine.facades.StoreFacadeImpl.create(StoreFacadeImpl.java:19)
[error]     at net.jqwik.api.lifecycle.Store.create(Store.java:67)
[error]     at net.jqwik.engine.hooks.statistics.StatisticsHook.aroundProperty(StatisticsHook.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$1(HookSupport.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$0(HookSupport.java:26)
[error]     at net.jqwik.engine.hooks.lifecycle.AutoCloseableHook.aroundProperty(AutoCloseableHook.java:13)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$1(HookSupport.java:31)
[error]     at net.jqwik.engine.execution.PropertyMethodExecutor.execute(PropertyMethodExecutor.java:47)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.executeTestMethod(PropertyTaskCreator.java:166)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.lambda$createTask$1(PropertyTaskCreator.java:51)
[error]     at net.jqwik.engine.execution.lifecycle.CurrentDomainContext.runWithContext(CurrentDomainContext.java:28)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.lambda$createTask$2(PropertyTaskCreator.java:50)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.lambda$execute$0(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.CurrentTestDescriptor.runWithDescriptor(CurrentTestDescriptor.java:17)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.execute(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionPipeline.runToTermination(ExecutionPipeline.java:82)
[error]     at net.jqwik.engine.execution.JqwikExecutor.execute(JqwikExecutor.java:46)
[error]     at net.jqwik.engine.JqwikTestEngine.executeTests(JqwikTestEngine.java:70)
[error]     at net.jqwik.engine.JqwikTestEngine.execute(JqwikTestEngine.java:53)

SimY4 avatar Aug 15 '23 12:08 SimY4

It started happening after I introduced some tests using jqwik-testing. Removing tests removes the issue. 🤷

SimY4 avatar Aug 15 '23 12:08 SimY4

Latest version of jqwik?

jlink avatar Aug 15 '23 13:08 jlink

One more question: Does it happen in the context of concurrent code or is everything in the tests running in a single thread?

jlink avatar Aug 15 '23 16:08 jlink

@jlink latwst released. 1.7.4

I'm not sure how SBT runs unit tests, I need to check. Instead of CME, sometimes it's becomes ArrayIndexOutOfBoundException in the same class. Something there is not ready to deal with what SBT is doing. I'll run some more experiments today.

SimY4 avatar Aug 15 '23 21:08 SimY4

I deployed a pathetically simple attempt to fix the problem on "1.8.0-SNAPSHOT". @SimY4 Maybe you'll find the time to try it.

jlink avatar Aug 16 '23 07:08 jlink

@SimY4 You could also try with disabling parallel tests in SBT as described here.

jlink avatar Aug 16 '23 07:08 jlink

Let me check. This is ArrayIndexOutOfBoundsException BTW for completeness:

java.lang.ArrayIndexOutOfBoundsException: Index 3 out of bounds for length 3, took 0.156s
[error]     at java.util.LinkedHashMap.valuesToArray(LinkedHashMap.java:555)
[error]     at java.util.LinkedHashMap$LinkedValues.toArray(LinkedHashMap.java:635)
[error]     at java.util.ArrayList.<init>(ArrayList.java:181)
[error]     at net.jqwik.engine.execution.lifecycle.StoreRepository.streamAllStores(StoreRepository.java:127)
[error]     at net.jqwik.engine.execution.lifecycle.StoreRepository.finishScope(StoreRepository.java:107)
[error]     at net.jqwik.engine.execution.ContainerTaskCreator.lambda$createTask$3(ContainerTaskCreator.java:91)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.lambda$execute$0(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.CurrentTestDescriptor.runWithDescriptor(CurrentTestDescriptor.java:17)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.execute(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionPipeline.runToTermination(ExecutionPipeline.java:82)
[error]     at net.jqwik.engine.execution.JqwikExecutor.execute(JqwikExecutor.java:46)
[error]     at net.jqwik.engine.JqwikTestEngine.executeTests(JqwikTestEngine.java:70)
[error]     at net.jqwik.engine.JqwikTestEngine.execute(JqwikTestEngine.java:53)

SimY4 avatar Aug 16 '23 07:08 SimY4

@jlink can confirm that Test / parallelExecution := false fixes this issue in SBT.

SimY4 avatar Aug 16 '23 07:08 SimY4

@jlink can confirm that Test / parallelExecution := false fixes this issue in SBT.

Then my fix has at least a chance of working. Try 1.8.0-SNAPSHOT.

jlink avatar Aug 16 '23 07:08 jlink

On latest snapshot I'm getting this most of the time (arbitrary in question varies from every run):

Test com.github.simy4.coregex.jqwik.JqwikTest.arbitraryTest failed: net.jqwik.api.CannotFindArbitraryException: Cannot find an Arbitrary for Parameter of type [@net.jqwik.api.ForAll(value="", supplier=net.jqwik.api.ArbitrarySupplier$NONE.class) Random], took 0.128s
[error]     at net.jqwik.engine.properties.RandomizedShrinkablesGenerator.resolveArbitraries(RandomizedShrinkablesGenerator.java:152)
[error]     at net.jqwik.engine.properties.RandomizedShrinkablesGenerator.resolveEdgeCases(RandomizedShrinkablesGenerator.java:124)
[error]     at net.jqwik.engine.properties.RandomizedShrinkablesGenerator.listOfEdgeCases(RandomizedShrinkablesGenerator.java:93)
[error]     at net.jqwik.engine.properties.RandomizedShrinkablesGenerator.forParameters(RandomizedShrinkablesGenerator.java:28)
[error]     at net.jqwik.engine.execution.CheckedProperty.createRandomizedShrinkablesGenerator(CheckedProperty.java:236)
[error]     at net.jqwik.engine.execution.CheckedProperty.createForAllParametersGenerator(CheckedProperty.java:176)
[error]     at net.jqwik.engine.execution.CheckedProperty.createGenericProperty(CheckedProperty.java:144)
[error]     at net.jqwik.engine.execution.CheckedProperty.check(CheckedProperty.java:67)
[error]     at net.jqwik.engine.execution.PropertyMethodExecutor.executeProperty(PropertyMethodExecutor.java:90)
[error]     at net.jqwik.engine.execution.PropertyMethodExecutor.executeMethod(PropertyMethodExecutor.java:69)
[error]     at net.jqwik.engine.execution.PropertyMethodExecutor.lambda$execute$0(PropertyMethodExecutor.java:49)
[error]     at net.jqwik.api.lifecycle.AroundPropertyHook.lambda$static$0(AroundPropertyHook.java:46)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$0(HookSupport.java:26)
[error]     at net.jqwik.api.lifecycle.PropertyExecutor.executeAndFinally(PropertyExecutor.java:39)
[error]     at net.jqwik.engine.hooks.lifecycle.PropertyLifecycleMethodsHook.aroundProperty(PropertyLifecycleMethodsHook.java:56)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$1(HookSupport.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$0(HookSupport.java:26)
[error]     at net.jqwik.engine.hooks.statistics.StatisticsHook.aroundProperty(StatisticsHook.java:37)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$1(HookSupport.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$0(HookSupport.java:26)
[error]     at net.jqwik.engine.hooks.lifecycle.AutoCloseableHook.aroundProperty(AutoCloseableHook.java:13)
[error]     at net.jqwik.engine.execution.lifecycle.HookSupport.lambda$wrap$1(HookSupport.java:31)
[error]     at net.jqwik.engine.execution.PropertyMethodExecutor.execute(PropertyMethodExecutor.java:47)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.executeTestMethod(PropertyTaskCreator.java:166)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.lambda$createTask$1(PropertyTaskCreator.java:51)
[error]     at net.jqwik.engine.execution.lifecycle.CurrentDomainContext.runWithContext(CurrentDomainContext.java:28)
[error]     at net.jqwik.engine.execution.PropertyTaskCreator.lambda$createTask$2(PropertyTaskCreator.java:50)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.lambda$execute$0(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.lifecycle.CurrentTestDescriptor.runWithDescriptor(CurrentTestDescriptor.java:17)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionTask$1.execute(ExecutionTask.java:31)
[error]     at net.jqwik.engine.execution.pipeline.ExecutionPipeline.runToTermination(ExecutionPipeline.java:82)
[error]     at net.jqwik.engine.execution.JqwikExecutor.execute(JqwikExecutor.java:46)
[error]     at net.jqwik.engine.JqwikTestEngine.executeTests(JqwikTestEngine.java:70)
[error]     at net.jqwik.engine.JqwikTestEngine.execute(JqwikTestEngine.java:53)

Some other things I observed less frequently:

  • ArrayIndexOutOfBounds
  • StreamCorruptionException during deserialization of .jqwik-database

SimY4 avatar Aug 16 '23 07:08 SimY4

That all suggests that SBT test parallelisation does things that are not compatible with the way jqwik currently works. I don’t know how fine-grained it can be switched off (eg for jqwik only) and if this has severe performance penalties for your build, though.

jlink avatar Aug 16 '23 08:08 jlink

@SimY4 To dive deeper and to enable this kind of parallelisation I'd need a test field for exploring SBT parallelisation. If you find the time to provide a minimum project using SBT running several jqwik tests, I'll look into the underlying problems. Not now, but when 1.8.0 will be done and deployed.

jlink avatar Aug 16 '23 09:08 jlink

Assumption: SBT is using several instances of the test engine concurrently. Probably via several launcher instances or starting launches in parallel threads.

Potential Problems

  • Access to singletons like StoreRepostiory are not prepared for that
  • ThreadLocals may not work as expected
  • Generator caching may not work
  • Serialization and Deserialization of jqwik database cannot cope
  • Lifecycle may get confused

jlink avatar Aug 16 '23 09:08 jlink

@jlink I reproduced it on this project: https://github.com/SimY4/coregex

Steps to reproduce:

  • remove Test / parallelExecution := false from jqwik project
  • run the build pipeline or for the faster dev loop:
sh> sbt
> project jqwik
> test

SimY4 avatar Aug 16 '23 10:08 SimY4

@SimY4 Many thanks

jlink avatar Aug 16 '23 11:08 jlink