[SUREFIRE-2135] On Unix-like OS and JDK 18+ Surefire kills the forked JVM if PpidChecker is active and argLine is set to -Dfile.encoding=UTF-16

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 3.0.0-M4, 3.0.0-M5, 3.0.0-M6, 3.0.0-M7
• Fix Version/s: 3.0.0-M8
• Component/s: process forking
• Environment: Unix-like OS, JDK 18 or higher
• Assignee: Slawomir Jaranowski
• Reporter: Andreas Pabst
• Created: 18/Dec/22 21:12
• Updated: 19/Dec/22 14:41
• Resolved: 19/Dec/22 14:41

Description

This breaks the continuous build on Java 18 and 19 because the integration test ConsoleOutputIT#properNewlinesAndEncodingWithDifferentEncoding fails.

Steps to reproduce

A minimum project to reproduce the issue requires a unit test and the following surefire configuration:

  <build>
     <plugins>
        <plugin>
           <groupId>org.apache.maven.plugins</groupId>
           <artifactId>maven-surefire-plugin</artifactId>
           <version>3.0.0-M7</version>
	       <configuration>
               <enableProcessChecker>all</enableProcessChecker>
           </configuration>
        </plugin>
     </plugins>
  </build>

The following output will be produced upon executing mvn test:

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.0.0-M7:test (default-test) on project myproject:
[ERROR] Please refer to /home/ogapa/code/maven-samples/utf16/target/surefire-reports for the individual test results.
[ERROR] Please refer to dump files (if any exist) [date].dump, [date]-jvmRun[N].dump and [date].dumpstream.
[ERROR] The forked VM terminated without properly saying goodbye. VM crash or System.exit called?

with the following stacktrace

org.apache.maven.surefire.booter.SurefireBooterForkException: Error occurred in starting fork, check output in log
        at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:635)
        at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:311)
        at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:268)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1334)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1167)
        at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:931)
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137)
        at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2(MojoExecutor.java:370)
        at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute(MojoExecutor.java:351)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:215)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:171)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:163)
        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:56)
        at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:294)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192)
        at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105)
        at org.apache.maven.cli.MavenCli.execute(MavenCli.java:960)
        at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:293)
        at org.apache.maven.cli.MavenCli.main(MavenCli.java:196)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
        at java.base/java.lang.reflect.Method.invoke(Method.java:577)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225)
        at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406)
        at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347)

All versions between 3.0.0-M4 and 3.0.0-M7 are affected. I could not reproduce it with versions before 3.0.0-M4.

Root cause analysis

In the log of the failed test the following line gives an indication as to what the cause is:

[ERROR] Surefire is going to kill self fork JVM. Maven process died.

Note: There is a race condition. If the test is fast enough (< 20 ms), the build may actually be successful despite the attempted killing of the self fork JVM. The exit code of the mvn process is still 1 though, not 0.

The above output is produced by the ForkedBooter class if PpidChecker#isProcessAlive returns false but the ping scheduler is not shut down yet.

Debugging into PpidChecker I found the reason why PpidChecker#isProcessAlive returns false:

The PpidChecker uses the command ps -o etime,pid <PID> to check if the elapsed time is still increasing, but if file.encoding is set to UTF-16, it fails to parse the ps output. Parsing fails because the java.util.Scanner it uses for that job is configured with Charset#defaultCharset, meaning it expects the InputStream of the ps output to produce UTF-16. It is however UTF-8 on basically all Unix-like systems.

So, how did this code work before Java 18?

It didn't. The only reason this didn't surface before is that there was another bug that prevented the PpidChecker from even getting that far. In Java versions < 18 the ProcessBuilder#start call fails if file.encoding is set to UTF-16, with an exception message saying "java.io.IOException: Cannot run program "/bin/sh": error=2, No such file or directory" which leads to PpidChecker#isProcessAlive throwing an exception. That exception leads to the process check being aborted, but is then swallowed in the ForkedBooter class.

The ProcessBuilder bug was apparently fixed in Java 18 which led to this problem surfacing.

Suggestion of a fix

In Java 17 the additional system property native.encoding was introduced. Since we are dealing with the output of a native OS command, this is the correct encoding to use for this particular use case - if it is present.

In case the system property is missing, we can use UTF-8 as a reasonable default since almost all modern Unix-like systems use UTF-8 as a system encoding by default.

So, when configuring the java.util.Scanner it uses to parse the output of the ps command, I suggest the PpidChecker should configure it based on the system property native.encoding and fall back to UTF-8 if the system property is absent, i.e. in Java versions before 17.

Issue Links

• links to: GitHub Pull Request #584