Andreas Pabst created SUREFIRE-2135:
---------------------------------------
Summary: 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
Key: SUREFIRE-2135
URL: https://issues.apache.org/jira/browse/SUREFIRE-2135
Project: Maven Surefire
Issue Type: Bug
Components: process forking
Affects Versions: 3.0.0-M7, 3.0.0-M6, 3.0.0-M5, 3.0.0-M4
Environment: Unix-like OS, JDK 18 or higher
Reporter: Andreas Pabst
This breaks the continuous build on Java 18 and 19 because the integration test
{{ConsoleOutputIT#properNewlinesAndEncodingWithDifferentEncoding}} fails.
h3. Steps to reproduce
A minimum project to reproduce the issue requires a unit test and the following
surefire configuration:
{code:xml}
<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>
{code}
The following output will be produced upon executing {{{}mvn test{}}}:
{noformat}
[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?
{noformat}
with the following stacktrace
{noformat}
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)
{noformat}
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.
h3. Root cause analysis
In the log of the failed test the following line gives an indication as to what
the cause is:
{noformat}
[ERROR] Surefire is going to kill self fork JVM. Maven process died.
{noformat}
_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.
h3. 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.
h3. Suggestion of a fix
In Java 17 the additional system property {{native.encoding}} was
[introduced|https://bugs.openjdk.org/browse/JDK-8266075]. 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.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
