New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Junit runner exits JVM with error 4 under experimental runner, no other messages #3638

Closed
ericzundel opened this Issue Jul 8, 2016 · 3 comments

Comments

Projects
None yet
1 participant
@ericzundel
Copy link
Member

ericzundel commented Jul 8, 2016

One of our teams ran into a long running test that at the end fails with:

FAILURE:
java org.pantsbuild.tools.junit.ConsoleRunner ... exited non-zero (4); 0 failed 0 targets.

When I was asked to debug it I remarked, "Its as if something called System.exit(4)"

Fortunately, we still have maven setup in our repo for one more week and found:

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-failsafe-plugin:2.19:integration-test (integration-test) on project acceptance-tests: Execution integration-test of goal org.apache.maven.plugins:maven-failsafe-plugin:2.19:integration-test failed: java.lang.RuntimeException: org.apache.maven.surefire.report.ReporterException: When writing report: /payjenkinsbuild/build-archives/regis-fullstack/workspace/payments/acceptance-tests/target/failsafe-reports/TEST-com.squareup.payments.acceptancetests.regis.RegisTenderAcceptanceIT[AddTenderAmountParameter.NORMAL_VALUE, TimeZoneParameter.NONE, MerchantParameter.JP_MERCHANT_AUTHORIZED_FOR_JCB, MediaTypeParameter.URL_ENCODED, CardTenderParameter.KEYED_EMPTY_AVS].xml (File name too long) -> [Help 1]
[ERROR] 

This is where the System.exit(4) is coming from:

src/java/org/pantsbuild/tools/junit/impl/ConsoleRunnerImpl.java
451:        // This error might be a call to `System.exit(0)`, which we definitely do
832:      System.exit(code);

And some information about the error:

Linux has a maximum filename length of 255 characters for most filesystems (including EXT4), and a maximum path of 4096 characters. eCryptfs is a layered filesystem. It stacks on top of another filesystem such as EXT4, which is actually used to write data to the disk. Feb 27, 2012

@ericzundel

This comment has been minimized.

Copy link
Member

ericzundel commented Jul 8, 2016

There is a bunch of code in AntJUnitXmlReportListener.java that declares throws java.lang.Exception but apprently there is no where else that reports these exceptions, so I'm going to catch them instead and log them before calling Throwables.propagate()

@ericzundel ericzundel changed the title Junit runner exits JVM with error 4 Junit runner exits JVM with error 4 under experimental runner, no other messages Jul 8, 2016

@ericzundel

This comment has been minimized.

Copy link
Member

ericzundel commented Jul 8, 2016

In the original report, tests were run with --test-junit-use-experimental-runner --test-junit-default-concurrency=PARALLEL_CLASSES_AND_METHODS.

I replicated the issue and with the legacy runner we get:

There was 1 failure:
1) Test mechanism
java.io.FileNotFoundException: /var/folders/42/8krm7t_50x98_6rxp7p0tv1w000205/T/junit2374099454843368995/testOutputDir/org.pantsbuild.tools.junit.lib.DescriptionTooLongTest[T1.A01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789, T2.B01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789, T3.C01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789].out.txt (File name too long)
    at java.io.FileOutputStream.open0(Native Method)
    at java.io.FileOutputStream.open(FileOutputStream.java:270)
    at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
    at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl$StreamCapture.getOutputStream(ConsoleRunnerImpl.java:109)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl$StreamCapturingListener.testStarted(ConsoleRunnerImpl.java:259)
    at org.pantsbuild.tools.junit.impl.ForwardingListener$3.fire(ForwardingListener.java:63)
    at org.pantsbuild.tools.junit.impl.ForwardingListener.fire(ForwardingListener.java:37)
    at org.pantsbuild.tools.junit.impl.ForwardingListener.testStarted(ForwardingListener.java:61)
    at org.pantsbuild.tools.junit.impl.AbortableListener.testStarted(AbortableListener.java:32)
    at org.junit.runner.notification.SynchronizedRunListener.testStarted(SynchronizedRunListener.java:49)
    at org.junit.runner.notification.RunNotifier$3.notifyListener(RunNotifier.java:121)
    at org.junit.runner.notification.RunNotifier$SafeNotifier.run(RunNotifier.java:72)
    at org.junit.runner.notification.RunNotifier.fireTestStarted(RunNotifier.java:118)
    at org.junit.internal.runners.model.EachTestNotifier.fireTestStarted(EachTestNotifier.java:42)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:323)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runners.Suite.runChild(Suite.java:128)
    at org.junit.runners.Suite.runChild(Suite.java:27)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runners.Suite.runChild(Suite.java:128)
    at org.junit.runners.Suite.runChild(Suite.java:27)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.runLegacy(ConsoleRunnerImpl.java:509)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.run(ConsoleRunnerImpl.java:422)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.main(ConsoleRunnerImpl.java:804)
    at org.pantsbuild.tools.junit.lib.ConsoleRunnerTestBase.invokeConsoleRunner(ConsoleRunnerTestBase.java:127)
    at org.pantsbuild.tools.junit.impl.ConsoleRunnerTest.testDescriptionTooLong(ConsoleRunnerTest.java:411)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
    at org.junit.rules.RunRules.evaluate(RunRules.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runners.Suite.runChild(Suite.java:128)
    at org.junit.runners.Suite.runChild(Suite.java:27)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

FAILURES!!!
Tests run: 1,  Failures: 1

But in the experimental runner, we get no such message. The "Tech mechanism" error is generated inside of JUnit code.

ericzundel added a commit to ericzundel/pants that referenced this issue Jul 10, 2016

Mimic an issue report in pantsbuild#3638 where
a failure from testRunFinished() in a listener aborts the test but otherwise gives no error messages.

ericzundel added a commit that referenced this issue Jul 12, 2016

Log exceptions from testRunFinished() in our listener
Mimics an issue report in #3638 where a failure from testRunFinished() in a listener aborts the test but otherwise gives no error messages.

In the scenario we saw in the field, an operating system error creating a file caused the tests to not failures, but no indication why.  Before this change, pants would return something like:

```
E
Time: 0

OK
(0 tests)
ConsoleRunner exited with status 1
```

After this change, we at least print the exception to the console:

```
java.io.IOException: Bogus IOException
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerTest$1AbortInTestRunFinishedListener.testRunFinished(ConsoleRunnerTest.java:424)
	at org.pantsbuild.tools.junit.impl.ForwardingListener$2.fire(ForwardingListener.java:54)
	at org.pantsbuild.tools.junit.impl.ForwardingListener.fire(ForwardingListener.java:37)
	at org.pantsbuild.tools.junit.impl.ForwardingListener.testRunFinished(ForwardingListener.java:52)
	at org.pantsbuild.tools.junit.impl.AbortableListener.testRunFinished(AbortableListener.java:32)
	at org.junit.runner.notification.SynchronizedRunListener.testRunFinished(SynchronizedRunListener.java:42)
	at org.junit.runner.notification.RunNotifier$2.notifyListener(RunNotifier.java:103)
	at org.junit.runner.notification.RunNotifier$SafeNotifier.run(RunNotifier.java:72)
	at org.junit.runner.notification.RunNotifier.fireTestRunFinished(RunNotifier.java:100)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.runLegacy(ConsoleRunnerImpl.java:516)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.run(ConsoleRunnerImpl.java:429)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.main(ConsoleRunnerImpl.java:811)
	at org.pantsbuild.tools.junit.lib.ConsoleRunnerTestBase.invokeConsoleRunner(ConsoleRunnerTestBase.java:129)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerTest.testRunFinishFailed(ConsoleRunnerTest.java:431)

...
Time: 0.011

OK
(0 tests)
ConsoleRunner exited with status 1
```

Testing Done:
Manually verified that debug output is being written in this case when running tests in IJ.

In the future when a new test runner is published, we could add an integration test that verifies that these messages make it to the console.

CI green at https://travis-ci.org/pantsbuild/pants/builds/143723517

Bugs closed: 3638, 3645

Reviewed at https://rbcommons.com/s/twitter/r/4060/
@ericzundel

This comment has been minimized.

Copy link
Member

ericzundel commented Jul 12, 2016

Commit d79a7a3

@ericzundel ericzundel closed this Jul 12, 2016

digwanderlust added a commit to digwanderlust/pants that referenced this issue Jul 15, 2016

Log exceptions from testRunFinished() in our listener
Mimics an issue report in pantsbuild#3638 where a failure from testRunFinished() in a listener aborts the test but otherwise gives no error messages.

In the scenario we saw in the field, an operating system error creating a file caused the tests to not failures, but no indication why.  Before this change, pants would return something like:

```
E
Time: 0

OK
(0 tests)
ConsoleRunner exited with status 1
```

After this change, we at least print the exception to the console:

```
java.io.IOException: Bogus IOException
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerTest$1AbortInTestRunFinishedListener.testRunFinished(ConsoleRunnerTest.java:424)
	at org.pantsbuild.tools.junit.impl.ForwardingListener$2.fire(ForwardingListener.java:54)
	at org.pantsbuild.tools.junit.impl.ForwardingListener.fire(ForwardingListener.java:37)
	at org.pantsbuild.tools.junit.impl.ForwardingListener.testRunFinished(ForwardingListener.java:52)
	at org.pantsbuild.tools.junit.impl.AbortableListener.testRunFinished(AbortableListener.java:32)
	at org.junit.runner.notification.SynchronizedRunListener.testRunFinished(SynchronizedRunListener.java:42)
	at org.junit.runner.notification.RunNotifier$2.notifyListener(RunNotifier.java:103)
	at org.junit.runner.notification.RunNotifier$SafeNotifier.run(RunNotifier.java:72)
	at org.junit.runner.notification.RunNotifier.fireTestRunFinished(RunNotifier.java:100)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.runLegacy(ConsoleRunnerImpl.java:516)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.run(ConsoleRunnerImpl.java:429)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.main(ConsoleRunnerImpl.java:811)
	at org.pantsbuild.tools.junit.lib.ConsoleRunnerTestBase.invokeConsoleRunner(ConsoleRunnerTestBase.java:129)
	at org.pantsbuild.tools.junit.impl.ConsoleRunnerTest.testRunFinishFailed(ConsoleRunnerTest.java:431)

...
Time: 0.011

OK
(0 tests)
ConsoleRunner exited with status 1
```

Testing Done:
Manually verified that debug output is being written in this case when running tests in IJ.

In the future when a new test runner is published, we could add an integration test that verifies that these messages make it to the console.

CI green at https://travis-ci.org/pantsbuild/pants/builds/143723517

Bugs closed: 3638, 3645

Reviewed at https://rbcommons.com/s/twitter/r/4060/
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment