Corrupted STDOUT by directly writing to native stream in forked JVM 1 testcontainers

Hi,
I've a Spring Boot project which uses TestContainers Azure Module to start a CosmosDB container for integration tests. When running integration tests in local, it works fine but on Jenkins I get the following error and TestContainers fail to start:

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-failsafe-plugin:2.22.2:verify (default-integration-test) on project aemsubscriptionservice: There are test failures.
[ERROR] 
[ERROR] Please refer to /var/jenkins/workspace/aem-subscription-service-pr/target/failsafe-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] org.apache.maven.surefire.booter.SurefireBooterForkException: ExecutionException The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd /var/jenkins/workspace/aem-subscription-service-pr && /var/jenkins/tools/hudson.model.JDK/java11/jdk-11.0.1/bin/java '-javaagent:/home/centos/.m2/repository/org/jacoco/org.jacoco.agent/0.8.6/org.jacoco.agent-0.8.6-runtime.jar=destfile=/var/jenkins/workspace/aem-subscription-service-pr/target/jacoco-it.exec,excludes=**/config/*:**/constants/*:**/*Application.*' -Dspring.profiles.active=test -Dlogging.path=/var/jenkins/workspace/aem-subscription-service-pr/target/logs -jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire/surefirebooter1671131972929134754.jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire 2022-03-05T08-22-19_195-jvmRun1 surefire15013675109974730189tmp surefire_08307517855808540324tmp
[ERROR] Error occurred in starting fork, check output in log
[ERROR] Process Exit Code: 134
[ERROR] ExecutionException The forked VM terminated without properly saying goodbye. VM crash or System.exit called?
[ERROR] Command was /bin/sh -c cd /var/jenkins/workspace/aem-subscription-service-pr && /var/jenkins/tools/hudson.model.JDK/java11/jdk-11.0.1/bin/java '-javaagent:/home/centos/.m2/repository/org/jacoco/org.jacoco.agent/0.8.6/org.jacoco.agent-0.8.6-runtime.jar=destfile=/var/jenkins/workspace/aem-subscription-service-pr/target/jacoco-it.exec,excludes=**/config/*:**/constants/*:**/*Application.*' -Dspring.profiles.active=test -Dlogging.path=/var/jenkins/workspace/aem-subscription-service-pr/target/logs -jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire/surefirebooter10682495641985064442.jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire 2022-03-05T08-22-19_195-jvmRun1 surefire5373890776979832691tmp surefire_18913741801050532438tmp
[ERROR] Error occurred in starting fork, check output in log
[ERROR] Process Exit Code: 134
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.awaitResultsDone(ForkStarter.java:510)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkPerTestSet(ForkStarter.java:457)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:298)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:246)
[ERROR] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1183)
[ERROR] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1011)
[ERROR] 	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:857)
[ERROR] 	at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137)
[ERROR] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:210)
[ERROR] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:156)
[ERROR] 	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:148)
[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:56)
[ERROR] 	at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
[ERROR] 	at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:305)
[ERROR] 	at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192)
[ERROR] 	at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105)
[ERROR] 	at org.apache.maven.cli.MavenCli.execute(MavenCli.java:972)
[ERROR] 	at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:293)
[ERROR] 	at org.apache.maven.cli.MavenCli.main(MavenCli.java:196)
[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:566)
[ERROR] 	at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282)
[ERROR] 	at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225)
[ERROR] 	at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406)
[ERROR] 	at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347)
[ERROR] Caused by: 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 /var/jenkins/workspace/aem-subscription-service-pr && /var/jenkins/tools/hudson.model.JDK/java11/jdk-11.0.1/bin/java '-javaagent:/home/centos/.m2/repository/org/jacoco/org.jacoco.agent/0.8.6/org.jacoco.agent-0.8.6-runtime.jar=destfile=/var/jenkins/workspace/aem-subscription-service-pr/target/jacoco-it.exec,excludes=**/config/*:**/constants/*:**/*Application.*' -Dspring.profiles.active=test -Dlogging.path=/var/jenkins/workspace/aem-subscription-service-pr/target/logs -jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire/surefirebooter10682495641985064442.jar /var/jenkins/workspace/aem-subscription-service-pr/target/surefire 2022-03-05T08-22-19_195-jvmRun1 surefire5373890776979832691tmp surefire_18913741801050532438tmp
[ERROR] Error occurred in starting fork, check output in log
[ERROR] Process Exit Code: 134
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:669)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.access$600(ForkStarter.java:115)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$2.call(ForkStarter.java:444)
[ERROR] 	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$2.call(ForkStarter.java:420)
[ERROR] 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[ERROR] 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[ERROR] 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[ERROR] 	at java.base/java.lang.Thread.run(Thread.java:834)
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[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/MojoExecutionException

System information:
Jenkins: 2.319.3
Docker: Docker version 20.10.2, build 2291f61
Docker System info:

Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Build with BuildKit (Docker Inc., v0.5.1-docker)

Server:
 Containers: 1
  Running: 0
  Paused: 0
  Stopped: 1
 Images: 1
 Server Version: 19.03.11
 Storage Driver: overlay2
  Backing Filesystem: xfs
  Supports d_type: true
  Native Overlay Diff: true
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 269548fa27e0089a8b8278fc4fc781d7f65a939b
 runc version: ff819c7e9184c13b7c2607fe6c30ae19403a7aff
 init version: fec3683
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 3.10.0-1160.11.1.el7.x86_64
 Operating System: CentOS Linux 7 (Core)
 OSType: linux
 Architecture: x86_64
 CPUs: 2
 Total Memory: 7.431GiB
 ID: JYKK:DL55:YBD2:R7CN:6PAX:Y4NN:QLBT:6OG5:T3KP:IBNB:RZTV:2R2L
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

Surefire and Failsafe plugin version: 3.0.0-M5
TestContainers version: 1.16.3
Testcontainers.properties:

docker.client.strategy=org.testcontainers.dockerclient.UnixSocketClientProviderStrategy
checks.disable=true

Part of POM.xml that relates to the above error:

<plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-surefire-plugin</artifactId>
                <version>${maven-surefire-plugin.version}</version>
                <configuration>
                    <skipTests>${skip.unit.tests}</skipTests>
                    <argLine>${jacoco.agent.argLine} -Dspring.profiles.active=${spring.profiles.active}
                        -Dlogging.path=${spring.logging.path}
                    </argLine>
                    <excludes>
                        <exclude>**/*IntegrationTest.java</exclude>
                    </excludes>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-failsafe-plugin</artifactId>
                <version>${maven-failsafe-plugin.version}</version>
                <configuration>
                    <reuseForks>false</reuseForks>
                    <skipITs>${skip.unit.tests}</skipITs>
                    <argLine>${jacoco.agent.argLine} -Dspring.profiles.active=${spring.profiles.active}
                        -Dlogging.path=${spring.logging.path}
                    </argLine>
                    <includes>
                        <include>**/*IntegrationTest.java</include>
                    </includes>
                    <classesDirectory>${project.build.outputDirectory}</classesDirectory>
                </configuration>
                <executions>
                    <execution>
                        <id>default-integration-test</id>
                        <goals>
                            <goal>integration-test</goal>
                            <goal>verify</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>
            <plugin>
                <groupId>org.jacoco</groupId>
                <artifactId>jacoco-maven-plugin</artifactId>
                <version>${jacoco.version}</version>
                <configuration>
                    <propertyName>jacoco.agent.argLine</propertyName>
                    <excludes>
                        <exclude>**/config/*</exclude>
                        <exclude>**/constants/*</exclude>
                        <exclude>**/*Application.*</exclude>
                    </excludes>
                </configuration>
                <executions>
                    <execution>
                        <id>default-prepare-agent</id>
                        <goals>
                            <goal>prepare-agent</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>default-prepare-agent-integration</id>
                        <goals>
                            <goal>prepare-agent-integration</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>default-report</id>
                        <goals>
                            <goal>report</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>default-report-integration</id>
                        <goals>
                            <goal>report-integration</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>default-merge</id>
                        <phase>verify</phase>
                        <goals>
                            <goal>merge</goal>
                        </goals>
                        <configuration>
                            <fileSets>
                                <fileSet implementation="org.apache.maven.shared.model.fileset.FileSet">
                                    <directory>${project.build.directory}</directory>
                                    <includes>
                                        <include>*.exec</include>
                                    </includes>
                                </fileSet>
                            </fileSets>
                            <destFile>${project.build.directory}/jacoco-all.exec</destFile>
                        </configuration>
                    </execution>
                    <execution>
                        <id>default-report-merged</id>
                        <phase>verify</phase>
                        <goals>
                            <goal>report</goal>
                        </goals>
                        <configuration>
                            <dataFile>${project.build.directory}/jacoco-all.exec</dataFile>
                            <outputDirectory>${project.reporting.outputDirectory}/jacoco-all</outputDirectory>
                        </configuration>
                    </execution>
                </executions>
            </plugin>

Below is the class definition in which I'm initializing TestContainers:

import com.azure.cosmos.CosmosAsyncClient;
import com.azure.cosmos.CosmosClientBuilder;
import com.azure.cosmos.models.CosmosDatabaseResponse;
import lombok.extern.log4j.Log4j2;
import org.junit.rules.TemporaryFolder;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;
import org.springframework.test.context.DynamicPropertyRegistry;
import org.springframework.test.context.DynamicPropertySource;
import org.testcontainers.containers.CosmosDBEmulatorContainer;
import org.testcontainers.junit.jupiter.Container;
import org.testcontainers.utility.DockerImageName;

import java.io.FileOutputStream;
import java.io.IOException;
import java.nio.file.Path;
import java.security.KeyStore;
import java.security.KeyStoreException;
import java.security.NoSuchAlgorithmException;
import java.security.cert.CertificateException;
import java.time.Duration;

import static org.assertj.core.api.Assertions.assertThat;
import static org.testcontainers.shaded.org.awaitility.Awaitility.await;

@SpringBootTest(classes = Application.class, webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
@ActiveProfiles("test")
@Log4j2
public abstract class AbstractIntegrationTest{
    @Container
    protected static CosmosDBEmulatorContainer cosmosDBEmulator;
    protected static CosmosAsyncClient client;
    protected static final TemporaryFolder tempFolder = TemporaryFolder.builder().assureDeletion().build();
    protected static final String dbName = "demo-notifications-test";

    static {
        try {
            cosmosDBEmulator = new CosmosDBEmulatorContainer(
                    DockerImageName.parse("mcr.microsoft.com/cosmosdb/linux/azure-cosmos-emulator:latest")
            ).withStartupTimeout(Duration.ofMinutes(10L))
                    .withEnv("AZURE_COSMOS_EMULATOR_PARTITION_COUNT", "3");
            cosmosDBEmulator.start();
            await().until(cosmosDBEmulator::isRunning);

            // make sure that containers will be stop in fast way (Ryuk can be slow)
            Runtime.getRuntime().addShutdownHook(new Thread(() -> {
                log.info("DockerContainers stop");
                cosmosDBEmulator.stop();
            }));

            tempFolder.create();
            Path keyStoreFile = tempFolder.newFile("azure-cosmos-emulator.keystore").toPath();
            KeyStore keyStore = cosmosDBEmulator.buildNewKeyStore();

            if (keyStore.containsAlias("azure-cosmos-emulator.keystore")) {
                keyStore.deleteEntry("azure-cosmos-emulator.keystore");
            }
            keyStore.store(new FileOutputStream(keyStoreFile.toFile()), cosmosDBEmulator.getEmulatorKey().toCharArray());

            System.setProperty("javax.net.ssl.trustStore", keyStoreFile.toString());
            System.setProperty("javax.net.ssl.trustStorePassword", cosmosDBEmulator.getEmulatorKey());
            System.setProperty("javax.net.ssl.trustStoreType", "PKCS12");

//            System.setProperty("azure.cosmos.uri", cosmosDBEmulator.getEmulatorEndpoint());
//            System.setProperty("azure.cosmos.key", cosmosDBEmulator.getEmulatorKey());
//            System.setProperty("azure.cosmos.secondaryKey", cosmosDBEmulator.getEmulatorKey());
//            System.setProperty("azure.cosmos.database", dbName);
//            System.setProperty("azure.cosmos.queryMetricsEnabled", String.valueOf(false));


            client = new CosmosClientBuilder()
                    .gatewayMode()
                    .endpointDiscoveryEnabled(false)
                    .endpoint(cosmosDBEmulator.getEmulatorEndpoint())
                    .key(cosmosDBEmulator.getEmulatorKey())
                    .buildAsyncClient();

            CosmosDatabaseResponse databaseResponse =
                    client.createDatabaseIfNotExists(dbName).block();
            assertThat(databaseResponse.getStatusCode()).isEqualTo(201);

        } catch (KeyStoreException | IOException | NoSuchAlgorithmException | CertificateException e) {
            cosmosDBEmulator.stop();
            System.exit(1);
        }
    }
    @DynamicPropertySource
    public static void cosmosDbProperties(DynamicPropertyRegistry registry) throws Exception {
        registry.add("azure.cosmos.uri", cosmosDBEmulator::getEmulatorEndpoint);
        registry.add("azure.cosmos.key", cosmosDBEmulator::getEmulatorKey);
        registry.add("azure.cosmos.secondaryKey", cosmosDBEmulator::getEmulatorKey);
        registry.add("azure.cosmos.database", () -> dbName);
        registry.add("azure.cosmos.queryMetricsEnabled", () -> String.valueOf(false));
    }
}

Logback configuration:

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type
             ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} %-5level %logger - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="debug">
        <appender-ref ref="STDOUT"/>
    </root>

    <logger name="com.github.dockerjava" level="WARN"/>
    <logger name="org.testcontainers" level="INFO"/>

</configuration>

Output from dumpstream:

# Created at 2022-03-05T08:27:35.479
Corrupted STDOUT by directly writing to native stream in forked JVM 1. Stream '# JRE version: OpenJDK Runtime Environment (11.0.1+13) (build 11.0.1+13)'.
java.lang.IllegalArgumentException: Stream stdin corrupted. Expected comma after third character in command '# JRE version: OpenJDK Runtime Environment (11.0.1+13) (build 11.0.1+13)'.
	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient$OperationalData.<init>(ForkClient.java:507)
	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.processLine(ForkClient.java:210)
	at org.apache.maven.plugin.surefire.booterclient.output.ForkClient.consumeLine(ForkClient.java:177)
	at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:88)
	at java.base/java.lang.Thread.run(Thread.java:834)

Also, I tried the same build after removing TestContainers and it worked fine.

Could you please help?
Thank you!

まず、Maven Failsafe 設定と報告されている Testcontainers.properties 設定を使って統合テストを再現し、次に fork された JVM の出力とダンプファイルを調査します。Jenkins のような環境で Testcontainers 統合テストが stdout を破損させたり fork された JVM を終了させたりせずに正常に実行されれば、修正は完了です。