search

junit-team / junit5

✅ The 5th major version of the programmer-friendly testing framework for Java and the JVM
https://junit.org
Eclipse Public License 2.0
6.41k stars 1.49k forks source link

JUnit vintage failing with "The forked VM terminated without properly saying goodbye" #801

Closed vmassol closed 7 years ago

vmassol commented 7 years ago

While building https://github.com/xwiki/xwiki-platform/tree/master/xwiki-platform-core/xwiki-platform-oldcore with vintage 4.12.0-M4 I get the error:

"The forked VM terminated without properly saying goodbye. VM crash or System.exit called?"

This module builds fine with "standard" Maven surefire:

        <plugin>
          <groupId>org.apache.maven.plugins</groupId>
          <artifactId>maven-surefire-plugin</artifactId>
          <version>2.19.1</version>
        </plugin>

But it fails when using:

<junit5.version>5.0.0-M4</junit5.version>
...
        <plugin>
          <groupId>org.apache.maven.plugins</groupId>
          <artifactId>maven-surefire-plugin</artifactId>
          <version>2.19.1</version>
          <dependencies>
            <!-- Allow running both JUnit4 and JUnit5 tests -->
            <dependency>
              <groupId>org.junit.platform</groupId>
              <artifactId>junit-platform-surefire-provider</artifactId>
              <version>1.0.0-M4</version>
            </dependency>
            <dependency>
              <groupId>org.junit.jupiter</groupId>
              <artifactId>junit-jupiter-engine</artifactId>
              <version>${junit5.version}</version>
            </dependency>
            <dependency>
              <groupId>org.junit.vintage</groupId>
              <artifactId>junit-vintage-engine</artifactId>
              <version>4.12.0-M4</version>
            </dependency>
          </dependencies>
        </plugin>

The console has:

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test (default-test) on project xwiki-platform-oldcore: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7554021871729302969.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire4900910245539098485tmp /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire_02307687931243988789tmp
[ERROR] -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test (default-test) on project xwiki-platform-oldcore: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
Command was /bin/sh -c cd /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7554021871729302969.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire4900910245539098485tmp /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire_02307687931243988789tmp
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:213)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:154)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:146)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:309)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:194)
    at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:107)
    at org.apache.maven.cli.MavenCli.execute(MavenCli.java:993)
    at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:345)
    at org.apache.maven.cli.MavenCli.main(MavenCli.java:191)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
Caused by: org.apache.maven.plugin.PluginExecutionException: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test failed: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
Command was /bin/sh -c cd /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7554021871729302969.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire4900910245539098485tmp /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire_02307687931243988789tmp
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:145)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
    ... 20 more
Caused by: java.lang.RuntimeException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
Command was /bin/sh -c cd /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7554021871729302969.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire4900910245539098485tmp /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefire_02307687931243988789tmp
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:590)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:460)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:229)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:201)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1026)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:862)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:755)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
    ... 21 more
[ERROR] 
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/PluginExecutionException

To reproduce:

Thanks!

vmassol commented 7 years ago

Would be great if this could be fixed for M5. This is currently preventing us from starting to use JUnit5 (using the vintage engine).

Any thought on this? Thanks a lot!

sormuras commented 7 years ago

Hi @vmassol -- I am no Maven/Surefire expert. But I don't see a class from our JUnit Platform Surefire Provider in the stacktrace you posted.

See section 4.2.2. Maven for configuration steps. Or this answered SO question: http://stackoverflow.com/questions/36970384/surefire-is-not-picking-up-junit-5-tests

Hope that helps.

vmassol commented 7 years ago

@sormuras Thanks. Here's what I do more precisely:

Step 1: Run "mvn clean install" on https://github.com/xwiki/xwiki-platform/tree/master/xwiki-platform-core/xwiki-platform-oldcore with the following surefire configuration:

        <plugin>
          <groupId>org.apache.maven.plugins</groupId>
          <artifactId>maven-surefire-plugin</artifactId>
          <version>2.19.1</version>
          <configuration>
            <trimStackTrace>false</trimStackTrace>
            <includes>
              <include>**/*Test.class</include>
            </includes>
          </configuration>
        </plugin>

Result: passing

Step 2: Run "mvn clean install" again but with the following changes to the pom.xml:

<junit5.version>5.0.0-M4</junit5.version>
...
        <plugin>
          <groupId>org.apache.maven.plugins</groupId>
          <artifactId>maven-surefire-plugin</artifactId>
          <version>2.19.1</version>
          <configuration>
            <trimStackTrace>false</trimStackTrace>
            <includes>
              <include>**/*Test.class</include>
            </includes>
          </configuration>
          <dependencies>
            <!-- Allow running both JUnit4 and JUnit5 tests -->
            <dependency>
              <groupId>org.junit.platform</groupId>
              <artifactId>junit-platform-surefire-provider</artifactId>
              <version>1.0.0-M4</version>
            </dependency>
            <dependency>
              <groupId>org.junit.jupiter</groupId>
              <artifactId>junit-jupiter-engine</artifactId>
              <version>${junit5.version}</version>
            </dependency>
            <dependency>
              <groupId>org.junit.vintage</groupId>
              <artifactId>junit-vintage-engine</artifactId>
              <version>4.12.0-M4</version>
            </dependency>
          </dependencies>
        </plugin>
...
      <dependency>
        <groupId>org.junit.jupiter</groupId>
        <artifactId>junit-jupiter-api</artifactId>
        <version>${junit5.version}</version>
      </dependency>

Result: Failing

This is full error with Maven executed with -X: https://gist.github.com/vmassol/358a0bcbb2c55f9172aa067c346aa6c2

This is the surefire configuration from the execution with Maven with -X: https://gist.github.com/vmassol/5214aa7c8cfe9888497a174ce281daa6

As you can see at line 76 (https://gist.github.com/vmassol/5214aa7c8cfe9888497a174ce281daa6#file-gistfile1-txt-L76), it says Using configured provider org.junit.platform.surefire.provider.JUnitPlatformProvider which seems to correspond to https://github.com/junit-team/junit5/blob/master/junit-platform-surefire-provider/src/main/java/org/junit/platform/surefire/provider/JUnitPlatformProvider.java

Since the only change in step2 is the change to use junit5 and junit5 surefire provider and the vintage engine, it seems to me that there's a problem somewhere in it causing the test to fail.

Unless you see some error in the way I configured junit5 to run our junit4 tests with Maven. But AFAIK I've followed the documentation and it works fine for building hundreds of other maven modules. It just fails on this one for some reason.

Thanks for your help.

vmassol commented 7 years ago

My guess is that the org.junit.platform.surefire.provider.JUnitPlatformProvider is somehow behaving differently than the default surefire provider for some condition.

marcphilipp commented 7 years ago

@Tibor17 Do you have an idea how to debug this?

Tibor17 commented 7 years ago

@marcphilipp Try to use version 2.20 and folow the message. It tells you to lookup .dump files in target folder with root cause happened in the fork.

Tibor17 commented 7 years ago

target/surefire-reports

marcphilipp commented 7 years ago

@vmassol Can you try using the latest snapshots of all JUnit 5 artifacts and see if the issue is still present?

vmassol commented 7 years ago

@marcphilipp will do ASAP and report back, thanks

vmassol commented 7 years ago

@marcphilipp could you tell me where to get the latest snapshots? I've found the CI job at https://junit.ci.cloudbees.com/job/JUnit5/ but I don't see where the generated artifacts are deployed to.

In order to build with snapshots I need a maven repo (installing them by hand in my local repo is doable but is a pain). Thanks

vmassol commented 7 years ago

ok found it at https://oss.sonatype.org/content/repositories/snapshots/org/junit/jupiter/

nipafx commented 7 years ago

@vmassol Maybe you took the wrong turn somewhere (the old junit5-... folders are really confusing)? Here are the recent snapshots of Vintage, for example, from yesterday.

vmassol commented 7 years ago

Thanks @nicolaiparlog , indeed I got confused initially but found the right artifacts by following the artifact ids from my pom :) Thx

vmassol commented 7 years ago

ok I've tried by adding the following to my pom.xml:

  <repositories>
    <repository>
      <id>sonatype-snapshots</id>
      <url>https://oss.sonatype.org/content/repositories/snapshots</url>
    </repository>
  </repositories>
  <pluginRepositories>
    <pluginRepository>
      <id>sonatype-snapshots2</id>
      <url>https://oss.sonatype.org/content/repositories/snapshots</url>
    </pluginRepository>
  </pluginRepositories>

And I get:

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test (default-test) on project xwiki-platform-oldcore: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test failed: An API incompatibility was encountered while executing org.apache.maven.plugins:maven-surefire-plugin:2.19.1:test: java.lang.NoSuchMethodError: org.apache.maven.surefire.util.internal.StringUtils.requireNonNull(Ljava/lang/Object;)Ljava/lang/Object;

Any idea?

vmassol commented 7 years ago

Maybe the snapshot version of the junit provider is not compatible with surefire 2.19.1 anymore?

marcphilipp commented 7 years ago

Yes, you have to switch to Surefire 2.20.

vmassol commented 7 years ago

ok so I get some more info:

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running com.xpn.xwiki.api.ContextTest
[WARNING] Corrupted stdin stream in forked JVM 1. See the dump file /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire-reports/2017-05-05T12-45-35_316-jvmRun1.dumpstream
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.174 s - in com.xpn.xwiki.api.ContextTest
[INFO] Running com.xpn.xwiki.api.DocumentTest
....
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 03:30 min
[INFO] Finished at: 2017-05-05T12:48:45+02:00
[INFO] Final Memory: 63M/1901M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.20:test (default-test) on project xwiki-platform-oldcore: There are test failures.
[ERROR] 
[ERROR] Please refer to /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/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 /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7006702630248129724.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire 2017-05-05T12-45-35_316-jvmRun1 surefire7277459393638560763tmp surefire_05454144741541036778tmp
[ERROR] Crashed tests:
[ERROR] com.xpn.xwiki.internal.xml.DOMXMLWriterTest
[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 /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore && /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/jre/bin/java -jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire/surefirebooter7006702630248129724.jar /Users/vmassol/dev/xwiki/xwiki-platform/xwiki-platform-core/xwiki-platform-oldcore/target/surefire 2017-05-05T12-45-35_316-jvmRun1 surefire7277459393638560763tmp surefire_05454144741541036778tmp
[ERROR] Crashed tests:
[ERROR] com.xpn.xwiki.internal.xml.DOMXMLWriterTest
[ERROR]     at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:679)
[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:279)
[ERROR]     at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:243)
[ERROR]     at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1077)
[ERROR]     at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:907)
[ERROR]     at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:785)
[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 sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[ERROR]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[ERROR]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[ERROR]     at java.lang.reflect.Method.invoke(Method.java:498)
[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 dump file has tons of those:

# Created on 2017-05-05T12:45:38.840
Corrupted stdin stream in forked JVM 1. Stream '12:45:38.836 [main] ERROR c.x.x.objects.classes.PropertyClass - Error while trying to evaluate if a property has a custom displayer'.
java.lang.IllegalArgumentException: Stream stdin corrupted. Expected comma after third character in command '12:45:38.836 [main] ERROR c.x.x.objects.classes.PropertyClass - Error while trying to evaluate if a property has a custom displayer'.
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient$OperationalData.<init>(ForkClient.java:469)
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.processLine(ForkClient.java:191)
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.consumeLine(ForkClient.java:158)
        at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:87)
        at java.lang.Thread.run(Thread.java:745)

# Created on 2017-05-05T12:45:38.841
Corrupted stdin stream in forked JVM 1. Stream 'java.lang.RuntimeException: Failed to load component for type [interface org.xwiki.template.TemplateManager] for hint [default]'.
java.lang.IllegalArgumentException: Stream stdin corrupted. Expected comma after third character in command 'java.lang.RuntimeException: Failed to load component for type [interface org.xwiki.template.TemplateManager] for hint [default]'.
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient$OperationalData.<init>(ForkClient.java:469)
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.processLine(ForkClient.java:191)
        at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.consumeLine(ForkClient.java:158)
        at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:87)
        at java.lang.Thread.run(Thread.java:745)

Any idea why this is passing fine with standard surefire but failing when using the junit5 surefire provider?

Thanks! We're getting closer...

vmassol commented 7 years ago

So the new thread dump stuff seems to be something new in surefire 2.20 (We also got it when trying to upgrade our build to surefire 2.20: https://jira.xwiki.org/browse/XCOMMONS-1190).

However the "The forked VM terminated without properly saying goodbye. VM crash or System.exit called?" is still there even when using the latest junit5 snapshot.

Tibor17 commented 7 years ago

You must be doing something in the fork like sending bytes to native std/out via {{FileDescriptor.out}} or {{ProcessBuilder and inherited channel}}.

On Fri, May 5, 2017 at 1:08 PM, Vincent Massol notifications@github.com wrote:

So the new thread dump stuff seems to be something new in surefire 2.20 (We also got it when trying to upgrade our build to surefire 2.20: https://jira.xwiki.org/browse/XCOMMONS-1190).

However the "The forked VM terminated without properly saying goodbye. VM crash or System.exit called?" is still there even when using the latest junit5 snapshot.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299438214, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yRyoYaiC4NeSH8Tw_rCNcpjgki9kxks5r2wMhgaJpZM4NEluL .

-- Cheers Tibor

Tibor17 commented 7 years ago

I guess it's the logger.

On Fri, May 5, 2017 at 1:15 PM, Tibor Digana tibor.digana@googlemail.com wrote:

You must be doing something in the fork like sending bytes to native std/out via {{FileDescriptor.out}} or {{ProcessBuilder and inherited channel}}.

On Fri, May 5, 2017 at 1:08 PM, Vincent Massol notifications@github.com wrote:

So the new thread dump stuff seems to be something new in surefire 2.20 (We also got it when trying to upgrade our build to surefire 2.20: https://jira.xwiki.org/browse/XCOMMONS-1190).

However the "The forked VM terminated without properly saying goodbye. VM crash or System.exit called?" is still there even when using the latest junit5 snapshot.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299438214, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yRyoYaiC4NeSH8Tw_rCNcpjgki9kxks5r2wMhgaJpZM4NEluL .

-- Cheers Tibor

-- Cheers Tibor

vmassol commented 7 years ago

Thanks! I'll try to understand that more and review our tests to check this out. What logger are you referring to BTW?

However on this comment https://issues.apache.org/jira/browse/SUREFIRE-1359?focusedCommentId=15969287&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-15969287 you say that it shouldn't fail the build.

So I'm still facing the issue of "The forked VM terminated without properly saying goodbye. VM crash or System.exit called?" which happens with junit5/vintage.

vmassol commented 7 years ago

So to make it clear:

Thanks

marcphilipp commented 7 years ago

The JUnit platform logs a few things (e.g. which engines are present) to stdin/stderr. You should be able to install a custom JUL LogManager (e.g. Log4J) and provide a config that suppresses all logging. Does that help?

Tibor17 commented 7 years ago

See ForkedBooter class in surefire. We are overriding system out/err in the beginning of the main() method. If you have any mechanism, like static code init, you can easily fetch System.out beforehand and this means you cached PrintStream and later you wrote bytes to the native stream and this is the issue.

On Fri, May 5, 2017 at 4:24 PM, Marc Philipp notifications@github.com wrote:

The JUnit platform logs a few things (e.g. which engines are present) to stdin/stderr. You should be able to install a custom JUL LogManager (e.g. Log4J) and provide a config that suppresses all logging. Does that help?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299478639, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yRwJJ35wBDlw6PfsC-9_qQfktGNG-ks5r2zEYgaJpZM4NEluL .

-- Cheers Tibor

vmassol commented 7 years ago

If you have any mechanism, like static code init, you can easily fetch System.out beforehand and this means you cached PrintStream and later you wrote bytes to the native stream and this is the issue.

ok that must be it. We do have code like this using SLF4J:

    private static final Logger LOGGER = LoggerFactory.getLogger(XWikiDocument.class);

I don't know what SLF4J does but maybe it caches PrintStream.

smoyer64 commented 7 years ago

I don't know what SLF4J does but maybe it caches PrintStream.

I think that depends on which implementation you bind into your test scope. If you don't provide an implementation, slf4j-nop will be used and I suspect it doesn't use System.out or System.err at all. It's also my recollection that slf4j-simple uses System.err though I can't comment on whether it's cached.

Tibor17 commented 7 years ago

What happens if you comment out the logger?

On Sat, May 6, 2017 at 7:23 PM, Steve Moyer notifications@github.com wrote:

I don't know what SLF4J does but maybe it caches PrintStream.

I think that depends on which implementation you bind into your test scope. If you don't provide an implementation, slf4j-nop will be used and I suspect it doesn't use System.out or System.err at all. It's also my recollection that slf4j-simple uses System.err though I can't comment on whether it's cached.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299654145, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yR7JYymRXT49U7PJxlHbV0tnlM7rxks5r3KyjgaJpZM4NEluL .

-- Cheers Tibor

Tibor17 commented 7 years ago

See this https://jira.qos.ch/browse/SLF4J-395 https://jira.qos.ch/browse/SLF4J-389 and system property org.slf4j.simpleLogger.cacheOutputStream see the Javadoc https://www.slf4j.org/api/org/slf4j/impl/SimpleLogger.html

On Sat, May 6, 2017 at 9:56 PM, Tibor Digana tibor.digana@googlemail.com wrote:

What happens if you comment out the logger?

On Sat, May 6, 2017 at 7:23 PM, Steve Moyer notifications@github.com wrote:

I don't know what SLF4J does but maybe it caches PrintStream.

I think that depends on which implementation you bind into your test scope. If you don't provide an implementation, slf4j-nop will be used and I suspect it doesn't use System.out or System.err at all. It's also my recollection that slf4j-simple uses System.err though I can't comment on whether it's cached.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299654145, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yR7JYymRXT49U7PJxlHbV0tnlM7rxks5r3KyjgaJpZM4NEluL .

-- Cheers Tibor

-- Cheers Tibor

Tibor17 commented 7 years ago

We have two issues here. One is corrupted stream and the second is some error which crashed forked jvm which can be seen in dump files .dump and .dumpstream.

Tibor17 commented 7 years ago

See this in logs [ERROR] Crashed tests: [ERROR] com.xpn.xwiki.internal.xml.DOMXMLWriterTest It is obvious that this test could not complete. Maybe due to System.exit() . The *.dumpstream is reported by Maven process because corrupted stream was received by ForkClient in Maven process. The *.dumpstream can be reported with another name if Maven process sends corrupted stream or forked jvm receives corrupted stream.

vmassol commented 7 years ago

@Tibor17 The reason I raised this issue is because of the different surefire behavior I get when I run "mvn test" with the junit5 surefire provider (with the vintage engine) and when I run it without it. Without it, the test doesn't crash and the build is successful (even with surefire 2.20). So I raised this issue because I thought that you guys would be interested in ensuring the same behavior since it's supposed to be a drop-in replacement.

Now I'm not against working to fix whatever is making the junit5 surefire provider choke in our tests but that's beside the point of this issue. I do really appreciate all your comments to help me fix the issue in my tests though and I'll work to fix them.

WDYT? Is this something you're willing to explore fixing?

Thanks!

marcphilipp commented 7 years ago

WDYT? Is this something you're willing to explore fixing?

Sure! However, right now I don't have any idea what causes Surefire to choke when using our provider.

@Tibor17 Do you?

Tibor17 commented 7 years ago

We received blockers and we understood that people corrupt stream which is used for surefire's internal communication. Dumping the steam which does not have our markers is the way to prove it. We have also such users which send such binary stream we recognize as ours and the plugin then hangs. In the next release I am going to change the format of the stream and add "magic number". If the magic number does not match then we are sure it is not our stream and still can be avoided from processing it and would go to .dumpstream file. Much later in version 3.0 we will use sockets by default and this inter process communication would be chosen by user configuration. Receiving .dumpstream file should not crash the jvm. This means there is second problem in provider which can be found in another dump file /target/surefire-reports/*.dump or failsafe-reports directory.

On Sun, May 7, 2017 at 9:36 AM, Marc Philipp notifications@github.com wrote:

WDYT? Is this something you're willing to explore fixing?

Sure! However, right now I don't have any idea what causes Surefire to choke when using our provider.

@Tibor17 https://github.com/Tibor17 Do you?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/junit-team/junit5/issues/801#issuecomment-299688237, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_yR9yiabLC4FZCEI_WfdHSqjb0Mzlzks5r3XRwgaJpZM4NEluL .

-- Cheers Tibor

Tibor17 commented 7 years ago

I do not see the test DOMXMLWriterTest in JUnit 5 sources. Is there any typo?

Tibor17 commented 7 years ago

@vmassol Try to add DOMXMLWriterTest.java with all dependencies it needs to have in a pull request or in separate project with POM and we all should have a look. But it must be isolated from all unnecessary dependencies and code.

vmassol commented 7 years ago

I do not see the test DOMXMLWriterTest in JUnit 5 sources. Is there any typo?

It's here: https://github.com/xwiki/xwiki-platform/blob/master/xwiki-platform-core/xwiki-platform-oldcore/src/test/java/com/xpn/xwiki/internal/xml/DOMXMLWriterTest.java

I'll try to create a smaller project to make it simpler for you to reproduce.

Thanks -Vincent

Tibor17 commented 7 years ago

Do you reproduce it with Java Agent like in Jenkins?

Tibor17 commented 7 years ago

@marcphilipp Do you have SNAPSHOT deployments in Maven Central?

sormuras commented 7 years ago

Snapshots are here: https://oss.sonatype.org/content/repositories/snapshots

Tibor17 commented 7 years ago

@vmassol Pls add SNAPSHOT dependency to JUnit 5 and plugin repository URL. Thx.

vmassol commented 7 years ago

@Tibor17 Yes, I've been running junit5 SNAPSHOT artifacts since https://github.com/junit-team/junit5/issues/801#issuecomment-299276442. Have you made any recent change that you'd like me to test?

Do you reproduce it with Java Agent like in Jenkins?

Yes, the error was noticed on a jenkins agent. That's when I reverted my change to support junit5. See https://jira.xwiki.org/browse/XCOMMONS-1189?focusedCommentId=94726&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-94726 and the commits tab to see the commit and the reverts.

Thanks

vmassol commented 7 years ago

@Tibor17 Here's a small project reproducing the problem I have:

xwiki-junit5-vintage.tar.gz

Let me know if you can reproduce.

Comment out the following part of the pom.xml and it should pass successfully:

       <!--dependencies>
          <dependency>
            <groupId>org.junit.platform</groupId>
            <artifactId>junit-platform-surefire-provider</artifactId>
            <version>1.0.0-SNAPSHOT</version>
          </dependency>
          <dependency>
            <groupId>org.junit.jupiter</groupId>
            <artifactId>junit-jupiter-engine</artifactId>
            <version>${junit5.version}</version>
          </dependency>
          <dependency>
            <groupId>org.junit.vintage</groupId>
            <artifactId>junit-vintage-engine</artifactId>
            <version>4.12.0-SNAPSHOT</version>
          </dependency>
        </dependencies-->

Thanks

Tibor17 commented 7 years ago

@vmassol I've got this in dumpstream: Unexpected IOException: 6,1,com.xpn.xwiki.internal.xml.DOMXMLWriterTest,writeVersusWriteOpen,null,null,null and Unexpected IOException: 2,1,org.junit.platform.surefire.provider.JUnitPlatformProvider,com.xpn.xwiki.internal.xml.DOMXMLWriterTest,null,null,null The code 6 and 2 mean BOOTERCODE_TEST_SUCCEEDED and BOOTERCODE_TESTSET_COMPLETED. This happens if PrintStream.checkError() returns true. It could be any reason. For instance the stream was closed or anything else.

Tibor17 commented 7 years ago

@vmassol @marcphilipp Now I changed the command to mvn test -DforkCount=0 -e -nsu and this is the exception:

Caused by: org.apache.maven.surefire.util.SurefireReflectionException: java.lang.ClassNotFoundException: org.apache.maven.plugin.surefire.log.api.ConsoleLogger
        at org.apache.maven.plugin.surefire.CommonReflector.<init>(CommonReflector.java:56)
        at org.apache.maven.plugin.surefire.InPluginVMSurefireStarter.runSuitesInProcess(InPluginVMSurefireStarter.java:78)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1060)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:907)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:785)
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
        ... 21 more
Caused by: java.lang.ClassNotFoundException: org.apache.maven.plugin.surefire.log.api.ConsoleLogger
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.apache.maven.surefire.booter.IsolatedClassLoader.loadClass(IsolatedClassLoader.java:98)
        at org.apache.maven.plugin.surefire.CommonReflector.<init>(CommonReflector.java:52)
        ... 26 more

AFter I have removed the plugin dependencies I get: [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 [INFO] [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS

vmassol commented 7 years ago

@Tibor17 Thanks for looking into this. I'm trying to understand your last 2 messages and whether there's something I can do on my side to make the test pass with junit5+vintage? I don't understand why you're getting this exception in your last test and why surefire would miss some class. Any idea?

Thanks!

Tibor17 commented 7 years ago

@vmassol @marcphilipp hm, why you use the dependencies within the plugin? It must not be there! The classloader in provider and plugin itself are two different and therefore all dependencies must be in the project, like it always was with junit:4.12 using the scope test. What you can do is to deploy BOM like Arquillian Universe having dependencyManagement. Once you have it in your POM you can inherit a bunch of dependencies which play the same role. This way one dependency would fetch multiple dependencies and versions which are consistent.

vmassol commented 7 years ago

@Tibor17 I'm not sure what dependency you're referring to... I'm just following the junit5 tutorial for maven, see section 4.2.2 in http://junit.org/junit5/docs/current/user-guide/#running-tests-build

So I have which matches the doc AFAICS:

    <plugin>
        <groupId>org.apache.maven.plugins</groupId>
        <artifactId>maven-surefire-plugin</artifactId>
        <version>2.20</version>
        <!-- XWiki rule is to put test in *Test classes -->
        <configuration>
          <!-- We want to show nested stack traces to see what is the real problem when a test fails! -->
          <trimStackTrace>false</trimStackTrace>
          <includes>
            <include>**/*Test.class</include>
          </includes>
        </configuration>
        <dependencies>
          <dependency>
            <groupId>org.junit.platform</groupId>
            <artifactId>junit-platform-surefire-provider</artifactId>
            <version>1.0.0-SNAPSHOT</version>
          </dependency>
          <dependency>
            <groupId>org.junit.jupiter</groupId>
            <artifactId>junit-jupiter-engine</artifactId>
            <version>${junit5.version}</version>
          </dependency>
          <dependency>
            <groupId>org.junit.vintage</groupId>
            <artifactId>junit-vintage-engine</artifactId>
            <version>4.12.0-SNAPSHOT</version>
          </dependency>
        </dependencies>
      </plugin>

What's wrong?

Thanks

Tibor17 commented 7 years ago

If the provider junit-platform-surefire-provider is in plugins dependencies the provider crashes. I have no idea why it fails but providers like surefire-junit47 was always documented in plugin dependencies, but not the other dependencies. The provider has SPI and such jar is added to IsolatedClassLoader or to the Manifest of jar of forked JVM.

smoyer64 commented 7 years ago

I've been using that configuration for months and am not having the problem experienced by @vmassol. I'm still using version 2.19.1 of the maven-surefire-plugin with JUnit 5 version M4.

Tibor17 commented 7 years ago

Now I used Surefire version 2.19.1 with command mvn test -nsu -DforkCount=0 and the result is different. There is difference against 2.20 because you do NOT see test summary. It looks to me like System.exit, notice I used forkCount=0 in CLI.


[INFO] --- maven-surefire-plugin:2.19.1:test (default-test) @ xwiki-platform-oldcore ---
[WARNING] useSystemClassloader setting has no effect when not forking
Running com.xpn.xwiki.internal.xml.DOMXMLWriterTest

e:\tmp\xwiki-junit5-vintage>```