apache / apache/maven-surefire
[SUREFIRE-1509] Surefire reports randomly tests failing when forkCount=1 and reuseForks=true (default)
- Dominant language
- Java
- Stars
- 461
- Forks
- 588
- Avg merge
- 1d 8h
- Merged PRs (30d)
- 19
Description
**[Jochen Hebbrecht](https://issues.apache.org/jira/secure/ViewProfile.jspa?name=jochus)** opened **[SUREFIRE-1509](https://issues.apache.org/jira/browse/SUREFIRE-1509?redirect=false)** and commented
Hi,
We are currently running our tests on a Jenkins Docker slave with JVM 9.0.4.
We sometimes get the following error:
```
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.21.0:test (default-test) on project infrastructure: There are test failures.
[ERROR]
[ERROR] Please refer to /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure/target/surefire-reports for the individual test results.
[ERROR] Please refer to dump files (if any exist) [date]-jvmRun[N].dump, [date].dumpstream and [date]-jvmRun[N].dumpstream.
[ERROR] The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure && /home/jenkins/tools/hudson.model.JDK/Oracle_JDK9.0.4/jdk-9.0.4/bin/java -jar /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure/target/surefire/surefirebooter17596563106997267184.jar /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure/target/surefire 2018-03-29T07-17-04_821-jvmRun1 surefire4958487791742188143tmp surefire_05065886537426794674tmp
[ERROR] Error occurred in starting fork, check output in log
[ERROR] Process Exit Code: 137
[ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure && /home/jenkins/tools/hudson.model.JDK/Oracle_JDK9.0.4/jdk-9.0.4/bin/java -jar /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure/target/surefire/surefirebooter17596563106997267184.jar /home/jenkins/workspace/s-slaves-with-nfs-workspace-KSX7WOVQKBXQS2AOK25P73Y44WD22SHRHPXX6YF6DAMF7VIHGYCQ/infrastructure/target/surefire 2018-03-29T07-17-04_821-jvmRun1 surefire4958487791742188143tmp surefire_05065886537426794674tmp
[ERROR] Error occurred in starting fork, check output in log
[ERROR] Process Exit Code: 137
[ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:671)
[ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:533)
[ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:278)
[ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:244)
[ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1149)
[ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:978)
[ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:854)
[ERROR] at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
[ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
[ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:154)
[ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:146)
[ERROR] at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117)
[ERROR] at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81)
[ERROR] at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
[ERROR] at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
[ERROR] at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:309)
[ERROR] at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:194)
[ERROR] at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:107)
[ERROR] at org.apache.maven.cli.MavenCli.execute(MavenCli.java:993)
[ERROR] at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:345)
[ERROR] at org.apache.maven.cli.MavenCli.main(MavenCli.java:191)
[ERROR] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[ERROR] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[ERROR] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[ERROR] at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
[ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
[ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
[ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
```
The maven plugin is configured as:
```
org.apache.maven.plugins
maven-surefire-plugin
2.21.0
src/integration-tests/java/**
```
If we switch to Java 8 as JVM on the Jenkins slaves, we cannot reproduce this problem.
If we run the tests on our local PC with Java 9, we cannot reproduce this problem.
When we look at the Jenkins slave to the dumpstream file, we noticed the following:
```
$ cat 2018-03-29T07-17-16_684.dumpstream
1. Created on 2018-03-29T07:17:16.702
WARNING: An illegal reflective access operation has occurred
1. Created on 2018-03-29T07:17:16.715
WARNING: Illegal reflective access by org.springframework.cglib.core.ReflectUtils$1 (file:/home/jenkins/.m2/repository/org/springframework/spring-core/5.0.4.RELEASE/spring-core-5.0.4.RELEASE.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
1. Created on 2018-03-29T07:17:16.727
WARNING: Please consider reporting this to the maintainers of org.springframework.cglib.core.ReflectUtils$1
1. Created on 2018-03-29T07:17:16.739
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
1. Created on 2018-03-29T07:17:16.752
WARNING: All illegal access operations will be denied in a future release
1. Created on 2018-03-29T07:17:27.578
Killed
```
If we add forkCount=0 to the configuration, we cannot reproduce the problem, but then we're actually hiding it of course.
Can you help us indicating what we can do to investigate this problem? More logging? Which steps to debug? Etc, etc, ...
---
**Affects:** 2.21.0
Contributor guide
Research direction
Start with the reported dumpstream output and the fork configuration using Java 9, forkCount=1, and reuseForks=true. Compare runs on the Jenkins Docker slave and a local machine, including forkCount=0 as a diagnostic; done means the termination cause is established and a verified fix or regression coverage addresses it.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- build-system, testing
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100