Intermittent NullPointerException accessing StepEventBus.registeredListeners running concurrently with Cucumber 7 + JUnit 5 Platform

[hertzsprung]

What happened?

I've occasionally seen two similar stacktraces:

java.lang.NullPointerException: Cannot invoke "net.thucydides.model.steps.StepListener.testSuiteFinished()" because "stepListener" is null
        at net.thucydides.core.steps.StepEventBus.testSuiteFinished(StepEventBus.java:857)
        at io.cucumber.core.plugin.SerenityReporterParallel.cleanupTestResourcesForURI(SerenityReporterParallel.java:1008)
        at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
        at java.base/java.util.concurrent.CopyOnWriteArraySet.forEach(CopyOnWriteArraySet.java:425)
        at io.cucumber.core.plugin.SerenityReporterParallel.assureTestSuiteFinished(SerenityReporterParallel.java:1000)
        at io.cucumber.core.plugin.SerenityReporterParallel.handleTestRunFinished(SerenityReporterParallel.java:527)
        at io.cucumber.core.eventbus.AbstractEventPublisher.send(AbstractEventPublisher.java:51)
        at io.cucumber.core.eventbus.AbstractEventBus.send(AbstractEventBus.java:12)
        at io.cucumber.core.runtime.SynchronizedEventBus.send(SynchronizedEventBus.java:47)
        at io.cucumber.core.runtime.CucumberExecutionContext.emitTestRunFinished(CucumberExecutionContext.java:117)
        at io.cucumber.core.runtime.CucumberExecutionContext.finishTestRun(CucumberExecutionContext.java:104)
        at io.cucumber.junit.platform.engine.CucumberEngineExecutionContext.finishTestRun(CucumberEngineExecutionContext.java:126)
        at io.cucumber.junit.platform.engine.CucumberEngineDescriptor.ifChildren(CucumberEngineDescriptor.java:63)
        at io.cucumber.junit.platform.engine.CucumberEngineDescriptor.cleanUp(CucumberEngineDescriptor.java:48)
        at io.cucumber.junit.platform.engine.CucumberEngineDescriptor.cleanUp(CucumberEngineDescriptor.java:12)

    java.lang.NullPointerException: Cannot invoke "net.thucydides.model.steps.StepListener.takeScreenshots(java.util.List)" because "stepListener" is null
        at net.thucydides.core.steps.StepEventBus.takeScreenshots(StepEventBus.java:1207)
        at io.cucumber.core.plugin.SerenityReporterParallel.recordStepResult(SerenityReporterParallel.java:1025)
        at io.cucumber.core.plugin.SerenityReporterParallel.handleResult(SerenityReporterParallel.java:1017)
        at io.cucumber.core.plugin.SerenityReporterParallel.handleTestStepFinished(SerenityReporterParallel.java:512)
        at io.cucumber.core.eventbus.AbstractEventPublisher.send(AbstractEventPublisher.java:51)
        at io.cucumber.core.eventbus.AbstractEventBus.send(AbstractEventBus.java:12)
        at io.cucumber.core.runtime.SynchronizedEventBus.send(SynchronizedEventBus.java:47)
        at io.cucumber.core.runtime.ThreadLocalRunnerSupplier$LocalEventBus.send(ThreadLocalRunnerSupplier.java:62)
        at io.cucumber.core.runner.TestStep.emitTestStepFinished(TestStep.java:113)
        at io.cucumber.core.runner.TestStep.run(TestStep.java:64)
        at io.cucumber.core.runner.PickleStepTestStep.run(PickleStepTestStep.java:51)
        at io.cucumber.core.runner.TestCase.run(TestCase.java:84)
        at io.cucumber.core.runner.Runner.runPickle(Runner.java:75)
        at io.cucumber.junit.platform.engine.CucumberEngineExecutionContext.lambda$runTestCase$4(CucumberEngineExecutionContext.java:112)
        at io.cucumber.core.runtime.CucumberExecutionContext.lambda$runTestCase$5(CucumberExecutionContext.java:136)
        at io.cucumber.core.runtime.RethrowingThrowableCollector.executeAndThrow(RethrowingThrowableCollector.java:23)
        at io.cucumber.core.runtime.CucumberExecutionContext.runTestCase(CucumberExecutionContext.java:136)
        at io.cucumber.junit.platform.engine.CucumberEngineExecutionContext.runTestCase(CucumberEngineExecutionContext.java:109)

Cucumber/JUnit parallel execution is enabled with cucumber.execution.parallel.enabled=true. The SerenityReporterParallel is configured.

What did you expect to happen?

Tests to complete successfully.

Serenity BDD version

4.21

JDK version

21.0.4

Execution environment

Reproduced on MacOS and Linux, no web browser.

How to reproduce the bug.

I've struggled to reproduce this locally with an entire Serenity/Cucumber test run but I have reproduced with a minimal Kotlin code that accesses and modifies StepEventBus concurrently:

package net.thucydides.core.steps

import kotlinx.coroutines.asCoroutineDispatcher
import kotlinx.coroutines.launch
import kotlinx.coroutines.runBlocking
import net.serenitybdd.core.SerenityListeners
import net.serenitybdd.core.di.SerenityInfrastructure
import net.serenitybdd.model.environment.ConfiguredEnvironment
import net.serenitybdd.rest.RestStepListener
import org.junit.jupiter.api.Test
import java.util.concurrent.ForkJoinPool

class StepEventBusTest {
    @Test
    fun test() {
        val pool = ForkJoinPool(4).asCoroutineDispatcher()

        while (true) {
            val stepEventBus = StepEventBus(
                ConfiguredEnvironment.getEnvironmentVariables(),
                ConfiguredEnvironment.getConfiguration(),
            )
            SerenityListeners(stepEventBus, SerenityInfrastructure.getConfiguration())
            for (i in 1..1000) stepEventBus.registerListener(RestStepListener())

            runBlocking(pool) {
                val job1 = launch {
                    stepEventBus.dropAllListeners()
                }
                val job2 = launch {
                    stepEventBus.testRunFinished()
                }
                job1.join()
                job2.join()
            }
        }
    }
}

which soon crashes with:

    java.lang.NullPointerException: Cannot invoke "net.thucydides.model.steps.StepListener.testRunFinished()" because "stepListener" is null
        at net.thucydides.core.steps.StepEventBus.testRunFinished(StepEventBus.java:865)
        at net.thucydides.core.steps.StepEventBusTest$test$1$job2$1.invokeSuspend(StepEventBusTest.kt:31)

What I know so far

StepEventBus.registeredListeners is an ArrayList, meaning external synchronization is needed for concurrent access/modification.
StepEventBus is shared between all scenarios in a feature file (see SerenityReporterParallel.getStepEventBus(URI)), and Cucumber/JUnit 5 Platform runs scenarios in parallel.
But I've yet to pin down the exact behaviour that triggers concurrent access/modification.

How can we make it happen?

Work on this myself and propose a PR (with Serenity BDD team guidance)

[wakaleo]

I've seen this sometimes but never been able to reproduce it. The step event bus is designed to be threadsafe - I can only assume there is a case where it isn't. The test case is a good start. You may be onto something regarding the registeredListeners list.

[hertzsprung]

I've seen this sometimes but never been able to reproduce it. The step event bus is designed to be threadsafe - I can only assume there is a case where it isn't. The test case is a good start. You may be onto something regarding the registeredListeners list.

If StepEventBus is intended to be thread-safe without external synchronization then should we switch to CopyOnWriteArrayList? Also, I believe this problem gets worse with dozens of RestStepListeners registered to one StepEventBus. It seems that RestStepListener no longer executes any code and could be safely removed?

Happy to assist with a PR with some guidance 🙂

[wakaleo]

CopyOnWrite is definitely worth a try. I don't recall what the RestListener does, it may not be required any more, in which case we can certainly remove it.

[hertzsprung]

Not technically related to this issue, but I've also raised #3544 to avoid creating StepEventBuses but never using them. This could help with any further investigation into StepEventBus race conditions.

[hertzsprung]

Thanks for the PR reviews so far. There's one more PR outstanding, #3543, that should reduce concurrent operations on registeredListeners for serenity-rest-assured users. Otherwise, personally I'm happy to resolve this issue.

[hertzsprung]

I have a pipeline running Serenity every 30 minutes and I've seen no further occurrences of this bug over the last few days since 4.2.3 was released.