[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ on Windows10 and MinTTY(Cygwin) console
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972782#comment-16972782 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 9:10 PM: Here is an extract of an old build log on our CI that has the issue. I pasted relevant info: {code:java} [18:09:12]Step 1/7: build-maven (Maven) (33s)[18:09:13][Step 1/7] Using agent local repository at /opt/buildagent/system/jetbrains.maven.runner/maven.repo.local[18:09:13][Step 1/7] Initial M2_HOME not set[18:09:13][Step 1/7] Current M2_HOME = /opt/buildagent/tools/maven3_3[18:09:13][Step 1/7] PATH = /opt/buildagent/tools/maven3_3/bin:/opt/java/openjdk/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin[18:09:13][Step 1/7] Using watcher: /opt/buildagent/plugins/mavenPlugin/maven-watcher-jdk16/maven-watcher-agent.jar[18:09:13][Step 1/7] Initial MAVEN_OPTS not set[18:09:13][Step 1/7] Current MAVEN_OPTS not set[18:09:13][Step 1/7] Starting: /opt/java/openjdk/bin/java -DOctopusReleaseVersion=1 -DPROJECT_NAME=ltl-java-linehauloperations-ensemble -Dagent.home.dir=/opt/buildagent -Dagent.name=teamcity-agent-k8s-cluster-03-90c290fe-9c11-4765-9eb4-5bc8600ab84d -Dagent.ownPort=9090 -Dagent.work.dir=/opt/buildagent/work -Dbuild.number=1.0.0.22.9-SNAPSHOT-21 -Dbuild.vcs.number=10992cd3eda8b3961a39e5d4ff75190e1a19bf25 -Dbuild.vcs.number.1=10992cd3eda8b3961a39e5d4ff75190e1a19bf25 -Dbuild.vcs.number.XpoLtl_GithubXPO=10992cd3eda8b3961a39e5d4ff75190e1a19bf25 -Dclassworlds.conf=/opt/buildagent/temp/buildTmp/teamcity.m2.conf -Dcom.jetbrains.maven.watcher.report.file=/opt/buildagent/temp/buildTmp/maven-build-info.xml -Dcomponent=linehauloperations-ensemble -Dgcp_project=ltl-java-linehauloperations-ensemble -Djava.io.tmpdir=/opt/buildagent/temp/buildTmp -Dk8s_cluster=xpo-ltl-dev-gke-cluster-03 -Dmaven.home=/opt/buildagent/tools/maven3_3 -Dmaven.multiModuleProjectDirectory=/opt/buildagent/work/8d1ea2f96e40b6ad -Dmaven.repo.local=/opt/buildagent/system/jetbrains.maven.runner/maven.repo.local -Dteamcity.agent.cpuBenchmark=435 -Dteamcity.agent.dotnet.agent_url=http://localhost:9090/RPC2 -Dteamcity.agent.dotnet.build_id=2058 -Dteamcity.auth.password=*** -Dteamcity.auth.userId=TeamCityBuildId=2058 -Dteamcity.build.changedFiles.file=/opt/buildagent/temp/buildTmp/changedFiles436895329153164929.txt -Dteamcity.build.checkoutDir=/opt/buildagent/work/8d1ea2f96e40b6ad -Dteamcity.build.id=2058 -Dteamcity.build.properties.file=/opt/buildagent/temp/buildTmp/teamcity.build1424809028942160220.properties -Dteamcity.build.tempDir=/opt/buildagent/temp/buildTmp -Dteamcity.build.workingDir=/opt/buildagent/work/8d1ea2f96e40b6ad -Dteamcity.buildConfName=ltl-java-linehauloperations-ensemble-development -Dteamcity.buildType.id=XpoLtl_Java_Development_LtlJavaLinehauloperationsEnsembleDevelopment -Dteamcity.configuration.properties.file=/opt/buildagent/temp/buildTmp/teamcity.config3418460461704538667.properties -Dteamcity.maven.watcher.home=/opt/buildagent/plugins/mavenPlugin/maven-watcher-jdk16 -Dteamcity.projectName=Development -Dteamcity.runner.properties.file=/opt/buildagent/temp/buildTmp/teamcity.runner6062948348053628422.properties -Dteamcity.tests.recentlyFailedTests.file=/opt/buildagent/temp/buildTmp/testsToRunFirst6288640780621088159.txt "-Dteamcity.version=2019.1.3 (build 66439)" -classpath /opt/buildagent/tools/maven3_3/boot/plexus-classworlds-2.5.2.jar: org.codehaus.plexus.classworlds.launcher.Launcher -f /opt/buildagent/work/8d1ea2f96e40b6ad/pom.xml -B clean package -U -X -Dskip.server=true[18:09:13][Step 1/7] in directory: /opt/buildagent/work/8d1ea2f96e40b6ad[18:09:13][Step 1/7] Picked up JAVA_TOOL_OPTIONS: -XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap[18:09:13][Step 1/7] Apache Maven 3.3.9 (bb52d8502b132ec0a5a3f4c09453c07478323dc5; 2015-11-10T16:41:47+00:00)[18:09:13][Step 1/7] Maven home: /opt/buildagent/tools/maven3_3[18:09:13][Step 1/7] Java version: 1.8.0_192, vendor: Oracle Corporation[18:09:13][Step 1/7] Java home: /opt/java/openjdk/jre[18:09:13][Step 1/7] Default locale: en, platform encoding: UTF-8[18:09:13][Step 1/7] OS name: "linux", version: "4.14.137+", arch: "amd64", family: "unix"{code} {code:java} [18:09:45][Step 1/7] [INFO] Results:[18:09:45][Step 1/7] [INFO] [18:09:45][Step 1/7] [INFO] Tests run: 64, Failures: 0, Errors: 0, Skipped: 0[18:09:45][Step 1/7] [INFO] [18:09:45][Step 1/7] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.22.0:test (default-test) on project ltl-java-linehauloperations-ensemble: There are test failures. Please refer to /opt/buildagent/work/8d1ea2f96e40b6ad/target/surefire-reports for the individual test results. Please refer to dump files (if any exist) [date]-jvmRun[N].dump, [date].dumpstream and [date]-jvmRun[N].dumpstream. The forked VM terminated without properly saying goodbye.
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ on Windows10 and MinTTY(Cygwin) console
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972748#comment-16972748 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 8:34 PM: [~tibordigana] I talked to DevOps, we use an agent where all the CI steps runs. This agent is based on this docker image [https://hub.docker.com/r/jetbrains/teamcity-agent] and use an Ubuntu Bionic if I see correctly. Tomorrow I'll try run the CI pipeline with the 3.0.0-M3 version of the plugin and report back if the issue from this tickets happens there as well. I know I've said to you that the issue still occurred on our CI, but I didn't try M3 there. I want to make sure that the problem in our CI is the same as the reported issue here, and it is related to the console although our CI has an ubuntu was (Author: adolfo.cia): [~tibordigana] I talked to DevOps, we use an agent where all the CI steps runs. This agent is based on this docker image [https://hub.docker.com/r/jetbrains/teamcity-agent] and use an Ubuntu Bionic if I see correctly. Tomorrow I'll try run the CI pipeline with the 3.0.0-M3 version of the plugin and report back if the issue from this tickets happens there as well. I know I say to you that the issue still occurred on our CI, but I didn't try M3 there. I want to make sure that the problem in our CI is the same as the reported issue here, and it is related to the console although our CI has an ubuntu > Forked VM terminated without properly saying goodbye with AciveMQ on > Windows10 and MinTTY(Cygwin) console > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972614#comment-16972614 ] Tibor Digana edited comment on SUREFIRE-1631 at 11/12/19 4:50 PM: -- Yes, it is caused by the console. We found it together with our handson experiences in this JIRA issue, so it is related to the native console. We fixed three issues related to Alpine/BusyBox Linux but this issue on Windows does not have a workaround. Therefore t is beteer to disable the checkers and user will enable the best fitting one (ping or native). I would prefer the PING together with ZGC or Shenandoah Garbage Collector. Another GCs may pause the application for over one minute and that's the drawaback of the PING mechanism. The PING mechanism is triggered every 30 seconds. The native checker is faster but not reliable on Windows as we can see. The checker is useful when you kill the build on CI machine and you want the Surefire forked JVM to stop the tests asap and free all handlers used by the JVM on the file system. The {{enableProcessChecker}} will be released in 3.0.0-M4 in several days. was (Author: tibor17): Yes, it is caused by the console. We found it together with our handson experiences in this JIRA issue, so it is related to the native console. We fixed three issues related to Alpine/BusyBox Linux but this issue on Windows does not have a workaround. Therefore t is beteer to disable the checkers and user will enable the best fitting one (ping or native). I would prefer the PING together with ZGC or Shenandoah Garbage Collector. Another GCs may pause the application for over one minute and that's the drwaback of the PING mechanism. The PING mechanism is triggered every 30 seconds. The native checker is faster not not reliable on Windows. The checker is useful when you kill the build on CI machine and you want the Surefire forked JVM to stop the tests asap and free all handlers used byt the JVM on the file system. The {{enableProcessChecker}} will be released in 3.0.0-M4 in several days. > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972368#comment-16972368 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 1:02 PM: [~tibordigana] your build failed :( was (Author: adolfo.cia): [~tibordigana] build fail :( > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Fix For: 3.0.0-M4 > > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972332#comment-16972332 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 12:24 PM: - [~tibordigana] 3.0.0-SNAPSHOT {code:java} mvn -Dtest=GetImageThumbnailMinuetTest clean test -U {code} No changes :( {code:java} [INFO] [INFO] BUILD FAILURE [INFO] [INFO] Total time: 28.413 s [INFO] Finished at: 2019-11-12T09:18:39-03:00 [INFO] [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) on project ltl-java-linehauloperations-ensemble: There are test failures. [ERROR] [ERROR] Please refer to C:\liberty_development\workspaces\services\ltl-java-linehauloperations-ensemble\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? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530\surefirebooter6299009151736715710.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530 2019-11-12T09-18-29_447-jvmRun1 surefire2278304519788026291tmp surefire_05740206142647884844tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530\surefirebooter6299009151736715710.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530 2019-11-12T09-18-29_447-jvmRun1 surefire2278304519788026291tmp surefire_05740206142647884844tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:690) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:285) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:248) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1213) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1059) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:886) [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:956) [ERROR] at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288) [ERROR] at org.apache.maven.cli.MavenCli.main(MavenCli.java:192) [ERROR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [ERROR] at
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972332#comment-16972332 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 12:22 PM: - [~tibordigana] {code:java} mvn -Dtest=GetImageThumbnailMinuetTest clean test -U {code} No changes :( {code:java} [INFO] [INFO] BUILD FAILURE [INFO] [INFO] Total time: 28.413 s [INFO] Finished at: 2019-11-12T09:18:39-03:00 [INFO] [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) on project ltl-java-linehauloperations-ensemble: There are test failures. [ERROR] [ERROR] Please refer to C:\liberty_development\workspaces\services\ltl-java-linehauloperations-ensemble\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? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530\surefirebooter6299009151736715710.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530 2019-11-12T09-18-29_447-jvmRun1 surefire2278304519788026291tmp surefire_05740206142647884844tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530\surefirebooter6299009151736715710.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire5938653218136437530 2019-11-12T09-18-29_447-jvmRun1 surefire2278304519788026291tmp surefire_05740206142647884844tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:690) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:285) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:248) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1213) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1059) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:886) [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:956) [ERROR] at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288) [ERROR] at org.apache.maven.cli.MavenCli.main(MavenCli.java:192) [ERROR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [ERROR] at
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16972330#comment-16972330 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/12/19 12:18 PM: - [~tibordigana] Ok, I'll put that config in my pom and test. Give me a sec was (Author: adolfo.cia): [~tibordigana] Ok, I put that config in my pom and test. Give me a sec > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Fix For: 3.0.0-M4 > > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16971663#comment-16971663 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/11/19 3:04 PM: yeah, you are right, if I put twice {code:java} CMD /A /X /C "wmic process where (ProcessId=15672) get CreationDate"{code} I get the same output. But I do not see the behavior you described in the other comment. was (Author: adolfo.cia): yeah, you are right, if I put twice CMD /A /X /C "wmic process where (ProcessId=15672) get CreationDate" I get the same output. But I do not see the behavior you described in the other comment. > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16971652#comment-16971652 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/11/19 2:49 PM: It is a two step process, first you put {code:java} CMD /A /X /C "wmic process where (ProcessId=15672) get CreationDate"{code} , then starts cmd, and then you put {code:java} wmic process where (ProcessId=15672) get CreationDate{code} was (Author: adolfo.cia): It is a two step process, first you put CMD /A /X /C "wmic process where (ProcessId=15672) get CreationDate", then starts cmd, and then you put wmic process where (ProcessId=15672) get CreationDate > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: cmd.PNG, cmd2.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16971557#comment-16971557 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/11/19 1:56 PM: [~tibordigana] so the problem is within the consoles that runs the mvn commands/goals? Yes, I'm at work for the next 8 hours, tag me whenever you want me to test the fix. was (Author: adolfo.cia): [~tibordigana] so the problem is within the consoles that runs the mvn commands/goals? Yes, I'm at work for the next 8 hours, tag me wherever you want me to test the fix. > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: cmd.PNG, shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16971522#comment-16971522 ] Adolfo Cia edited comment on SUREFIRE-1631 at 11/11/19 1:21 PM: [~tibordigana] Ok, snapshot 3.0.0 didn't work (failed the fifth time I execute it): {code:java} [INFO] [INFO] BUILD FAILURE [INFO] [INFO] Total time: 9.047 s [INFO] Finished at: 2019-11-11T10:15:47-03:00 [INFO] [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) on project ltl-java-linehauloperations-ensemble: There are test failures. [ERROR] [ERROR] Please refer to C:\liberty_development\workspaces\services\ltl-java-linehauloperations-ensemble\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? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire1699052172262397174\surefirebooter94309476510590017.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire1699052172262397174 2019-11-11T10-15-44_326-jvmRun1 surefire4984701455985067123tmp surefire_01067224024401515361tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was cmd.exe /X /C "C:\liberty_development\wlp\java\java\jre\bin\java -javaagent:C:\Users\adolfo.cia\.m2\repository/org/jmockit/jmockit/1.48/jmockit-1.48.jar -jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire1699052172262397174\surefirebooter94309476510590017.jar C:\Users\adolfo.cia\AppData\Local\Temp\surefire1699052172262397174 2019-11-11T10-15-44_326-jvmRun1 surefire4984701455985067123tmp surefire_01067224024401515361tmp" [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] com.xpo.ltl.linehauloperations.service.ejb.v1.GetImageThumbnailMinuetTest [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:690) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:285) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:248) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1213) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1059) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:886) [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:956) [ERROR] at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288) [ERROR] at org.apache.maven.cli.MavenCli.main(MavenCli.java:192) [ERROR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [ERROR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:90)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16970993#comment-16970993 ] Tibor Digana edited comment on SUREFIRE-1631 at 11/10/19 1:29 AM: -- [~rockymm] [~adolfo.cia] I guess I know where is the problem but you should help me when you run this command and show me how it goes on your system (Windows 10). Pickup some PID from Task Manager, e.g. 10488: {{CMD /A /X /C wmic process where (ProcessId=10488) get CreationDate}} was (Author: tibor17): [~rockymm] [~adolfo.cia] I guess I know where is the problem but you should help when you run this command and show me how it goes on your system (Windows 10). Pickup some PID from Task Manager, e.g. 10488: {{CMD /A /X/ /C wmic process where (ProcessId=10488) get CreationDate}} > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16963964#comment-16963964 ] Tibor Digana edited comment on SUREFIRE-1631 at 10/31/19 1:05 PM: -- Have you seen the surefire dump files in {{target/surefire-reports}}? Would you attach them? Maybe we will see the errors. We may see native errors of JVM or OS/HDD (low disk space, or low memory) in there. It happens. was (Author: tibor17): Have you seen the surefire dump files in {{target/surefire-reports}}? Would you attach them? Maybe we will see the errors. We may see native errors of JVM in there. It happens. > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 2.22.0, 3.0.0-M2, 3.0.0-M1 >Reporter: Aaron Digulla >Assignee: Tibor Digana >Priority: Major > Attachments: shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian Jira (v8.3.4#803005)
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16961209#comment-16961209 ] Tibor Digana edited comment on SUREFIRE-1631 at 10/28/19 4:21 PM: -- [~digulla] Now I used the development version {{3.0.0-SNAPSHOT}} and I got this result. Due to the shutdown hook is called right before the EXIT, all the communication between Maven process and forked JVM has finished and the logs in the shutdown hook might be lost. {noformat} [INFO] --- maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) @ surefire-shutdownhook-bug --- [INFO] [INFO] --- [INFO] T E S T S [INFO] --- [INFO] Running org.apache.maven.surefire.bugs.shutdownhook.SomethingWhichInstallShutdownHookTest 17:17:24,779 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/C:/vcs/github/surefire-shutdownhook-bug/target/test-classes/logback-test.xml] 17:17:24,904 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 17:17:24,909 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT] 17:17:24,918 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 17:17:24,962 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 17:17:24,963 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT] 17:17:24,964 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 17:17:24,965 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5f2108b5 - Registering current configuration as safe fallback point 17:17:24.971 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 0 17:17:24.976 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 1 17:17:24.977 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 2 ... MORE LOGS HERE ... 17:17:30.660 [ShutdownHook which will write lots of stuff to stdout] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - installShutdownHook line 7906 Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. [INFO] [INFO] Results: [INFO] [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 [INFO] [INFO] [INFO] BUILD SUCCESS [INFO] [INFO] Total time: 10.640 s [INFO] Finished at: 2019-10-28T17:17:31+01:00 [INFO] Final Memory: 13M/594M [INFO] {noformat} was (Author: tibor17): [~digulla] Now I used the development version {{3.0.0-SNAPSHOT}} and I got this result. Due to the shutdown is called right before the EXIT, all the communication between Maven process and forked JVM has finished and the logs in the shutdown hook might be lost. {noformat} [INFO] --- maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) @ surefire-shutdownhook-bug --- [INFO] [INFO] --- [INFO] T E S T S [INFO] --- [INFO] Running org.apache.maven.surefire.bugs.shutdownhook.SomethingWhichInstallShutdownHookTest 17:17:24,779 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/C:/vcs/github/surefire-shutdownhook-bug/target/test-classes/logback-test.xml] 17:17:24,904 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 17:17:24,909 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT] 17:17:24,918 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 17:17:24,962 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 17:17:24,963 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT] 17:17:24,964 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 17:17:24,965 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5f2108b5 - Registering current configuration as
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16961209#comment-16961209 ] Tibor Digana edited comment on SUREFIRE-1631 at 10/28/19 4:18 PM: -- [~digulla] Now I used the development version {{3.0.0-SNAPSHOT}} and I got this result. Due to the shutdown is called right before the EXIT, all the communication between Maven process and forked JVM has finished and the logs in the shutdown hook might be lost. {noformat} [INFO] --- maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) @ surefire-shutdownhook-bug --- [INFO] [INFO] --- [INFO] T E S T S [INFO] --- [INFO] Running org.apache.maven.surefire.bugs.shutdownhook.SomethingWhichInstallShutdownHookTest 17:17:24,779 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/C:/vcs/github/surefire-shutdownhook-bug/target/test-classes/logback-test.xml] 17:17:24,904 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 17:17:24,909 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT] 17:17:24,918 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 17:17:24,962 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 17:17:24,963 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT] 17:17:24,964 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 17:17:24,965 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5f2108b5 - Registering current configuration as safe fallback point 17:17:24.971 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 0 17:17:24.976 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 1 17:17:24.977 [main] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - This is a short log message 2 ... MORE LOGS HERE ... 17:17:30.660 [ShutdownHook which will write lots of stuff to stdout] DEBUG o.a.m.s.b.s.SomethingWhichInstallShutdownHook - installShutdownHook line 7906 Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. [INFO] [INFO] Results: [INFO] [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 [INFO] [INFO] [INFO] BUILD SUCCESS [INFO] [INFO] Total time: 10.640 s [INFO] Finished at: 2019-10-28T17:17:31+01:00 [INFO] Final Memory: 13M/594M [INFO] {noformat} was (Author: tibor17): [~digulla] Now I used the development version {{3.0.0-SNAPSHOT}} and I got this result. Due to the shutdown is called right before the EXIT, all the communication between Maven process and forked JVM has finished and the logs in the shutdown hook might be lost. {noformat} [INFO] --- maven-surefire-plugin:3.0.0-SNAPSHOT:test (default-test) @ surefire-shutdownhook-bug --- [INFO] [INFO] --- [INFO] T E S T S [INFO] --- [INFO] Running org.apache.maven.surefire.bugs.shutdownhook.SomethingWhichInstallShutdownHookTest 17:09:25,306 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/C:/vcs/github/surefire-shutdownhook-bug/target/test-classes/logback-test.xml] 17:09:25,437 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 17:09:25,444 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT] 17:09:25,458 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 17:09:25,514 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 17:09:25,514 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT] 17:09:25,515 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 17:09:25,517 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5f2108b5 - Registering current configuration as safe
[jira] [Comment Edited] (SUREFIRE-1631) Forked VM terminated without properly saying goodbye with AciveMQ
[ https://issues.apache.org/jira/browse/SUREFIRE-1631?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16757109#comment-16757109 ] Aaron Digulla edited comment on SUREFIRE-1631 at 1/31/19 10:29 AM: --- I've attached a project which demonstrates the bug. Just compile it with {code}mvn clean install{code} Can someone please confirm this bug? was (Author: digulla): I've attached the test case. Can someone please confirm this bug? > Forked VM terminated without properly saying goodbye with AciveMQ > - > > Key: SUREFIRE-1631 > URL: https://issues.apache.org/jira/browse/SUREFIRE-1631 > Project: Maven Surefire > Issue Type: Bug > Components: Maven Surefire Plugin >Affects Versions: 2.20.1, 3.0.0-M1, 2.22.0, 3.0.0-M2 >Reporter: Aaron Digulla >Priority: Major > Attachments: shurefire-shutdownhook-bug-0.0.1.zip > > > I'm seeing spurious "The forked VM terminated without properly saying > goodbye. VM crash or System.exit called?" messages when running unit tests in > a big multi-module project. > OS: Windows 10, running Maven 3.5.0 to 3.6.0 and different versions of > Surefire (2.20.1 to 3.0.0.-M2), Java 8u171 to 8u191. > I'm running Maven from the command line using MinTTY (Cygwin). > Things I tried which have no effect: > * Reboot / Cold boot (happens first thing on Monday morning when I come into > the office and turn on my PC). > * More free memory (happens when I only have a single window open). I have > 16GB of RAM. > * Different terminal. I tried CMD prompt and urxvt (Cygwin/X). > * Different versions of the Surefire plugin or Maven > * Different JDK 8 builds > Things that affect the bug: > * Redirecting Maven's stdout to a file: mvn ... | tee mvn.log > * Redirecting all log output to a file using logback-test.xml > * Running Surefire with forkCount=0 > * Running a subset of the tests (-Dtest=...) > * Pending Windows updates (I think, not sure about this one). > Counts: I've never seen it with forkCount=0 (~ 20 test builds). I've never > seen it with redirecting log output (~ 10 builds). Redirecting sometimes > helps but not always. > One thing which I notice is that one of the tests creates an ActiveMQ broker > and uses a shutdown hook to stop it. So I created a small test project which > demonstrates that Surefire will sometimes cut off stdout. I think that > happens because the main process kills the child after a timeout (correct?). > So my guess would be that shutdown hooks can mess with the pipeline between > the surefire child VM and main Maven process. ActiveMQ might be worse since > it stops threads and execution pools (so the output comes slowly with a > couple of exceptions sprinkled in when one component loses connection because > another is shutting down). > But now, it gets weird. When the build succeeds, it takes about ~5 minutes to > run 1028 tests. The log is 25 MB. > When it fails, it takes ~8 minutes to run ~700-800 tests (this number varies) > and the log stops in the middle of a test but is also 25 MB. > Some of the time discrepancy is probably because writing to a file is faster > than printing on a terminal. The strange part is that the log file is about > the same size but 30% of the tests haven't run. Most tests log a lot, do I > would expect to see a difference of at least a few MB. The Maven part (which > contains escape sequences, etc). is just 60 KB. > Maybe the parent takes some part of the log output as "child terminated". > I'm running out of ideas what to try next. I think a way to log the > communication between parent and child would help. Also the parent should > terminate the child and then read stdout until EOF to we can see anything > that happens afterwards. -- This message was sent by Atlassian JIRA (v7.6.3#76005)