Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 313201

Summary: Test failure on /jetty-client
Product: [RT] Jetty Reporter: Joakim Erdfelt <joakim.erdfelt>
Component: buildAssignee: Joakim Erdfelt <joakim.erdfelt>
Status: CLOSED WORKSFORME QA Contact:
Severity: normal    
Priority: P3 CC: gregw, jetty-inbox, mgorovoy
Version: 7.1.0   
Target Milestone: 7.0.2.RC0   
Hardware: PC   
OS: Linux   
Whiteboard:

Description Joakim Erdfelt CLA 2010-05-17 13:39:22 EDT
-------------------------------------------------------------------------------
Test set: org.eclipse.jetty.client.SslSecuredErrorStatusTest
-------------------------------------------------------------------------------
Tests run: 20, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 2.239 sec <<< FAILURE!
testPutNotFound(org.eclipse.jetty.client.SslSecuredErrorStatusTest)  Time elapsed: 0.109 sec  <<< FAILURE!
junit.framework.AssertionFailedError: expected:<404> but was:<0>
	at junit.framework.Assert.fail(Assert.java:47)
	at junit.framework.Assert.failNotEquals(Assert.java:280)
	at junit.framework.Assert.assertEquals(Assert.java:64)
	at junit.framework.Assert.assertEquals(Assert.java:198)
	at junit.framework.Assert.assertEquals(Assert.java:204)
	at org.eclipse.jetty.client.ErrorStatusTest.doPutFail(ErrorStatusTest.java:140)
	at org.eclipse.jetty.client.ErrorStatusTest.testPutNotFound(ErrorStatusTest.java:59)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at junit.framework.TestCase.runTest(TestCase.java:164)
	at junit.framework.TestCase.runBare(TestCase.java:130)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:120)
	at junit.framework.TestSuite.runTest(TestSuite.java:230)
	at junit.framework.TestSuite.run(TestSuite.java:225)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.junit.JUnitTestSet.execute(JUnitTestSet.java:213)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
	at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338)
	at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997)


The following was also seen in the logs
2010-05-17 10:33:57.547:WARN::CONNECTION FAILED ContentExchange@21704474=PUT//localhost:38599/output.txt#9
java.net.ConnectException: Connection refused
	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
	at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:675)
	at org.eclipse.jetty.io.nio.SelectorManager.doSelect(SelectorManager.java:186)
	at org.eclipse.jetty.client.SelectConnector.run(SelectConnector.java:180)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436)
	at java.lang.Thread.run(Thread.java:619)
Comment 1 Joakim Erdfelt CLA 2010-05-24 17:06:19 EDT
ulimit bump to 20,000 open files fixed the reported test failure.

*BUT* it introduced a new test failure (not 100% repeatable)

-------------------------------------------------------------------------------
Test set: org.eclipse.jetty.client.SslSecuredContentExchangeTest
-------------------------------------------------------------------------------
Tests run: 4, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.469 sec <<< FAILURE!
testGet(org.eclipse.jetty.client.SslSecuredContentExchangeTest)  Time elapsed: 0.058 sec  <<< ERROR!
java.lang.NumberFormatException: -2
	at org.eclipse.jetty.util.TypeUtil.parseInt(TypeUtil.java:301)
	at org.eclipse.jetty.http.HttpURI.parse2(HttpURI.java:482)
	at org.eclipse.jetty.http.HttpURI.parse(HttpURI.java:110)
	at org.eclipse.jetty.http.HttpURI.<init>(HttpURI.java:92)
	at org.eclipse.jetty.client.HttpExchange.setURL(HttpExchange.java:343)
	at org.eclipse.jetty.client.ContentExchangeTest.testGet(ContentExchangeTest.java:132)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at junit.framework.TestCase.runTest(TestCase.java:164)
	at junit.framework.TestCase.runBare(TestCase.java:130)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:120)
	at junit.framework.TestSuite.runTest(TestSuite.java:230)
	at junit.framework.TestSuite.run(TestSuite.java:225)
	at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.junit.JUnitTestSet.execute(JUnitTestSet.java:213)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
	at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338)
	at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997)
Comment 2 Greg Wilkins CLA 2010-06-09 03:33:01 EDT
This looks vaguely related to the hadoop issue.  Can you investigate.
Comment 3 Joakim Erdfelt CLA 2010-06-09 17:10:57 EDT
I am unable to replicate this bug since fixing my ulimit on "open files".
Comment 4 Greg Wilkins CLA 2010-06-09 18:59:42 EDT
reopen if it reoccurs
Comment 5 Joakim Erdfelt CLA 2010-06-15 18:51:16 EDT
Had it happen again today (Jun 15, 2010).
And I do have the ulimit setup properly.
I will attempt to replicate (again).

-------------------------------------------------------------------------------
Test set: org.eclipse.jetty.client.HttpHeadersTest
-------------------------------------------------------------------------------
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.116 sec <<< FAILURE!
testHttpHeaders(org.eclipse.jetty.client.HttpHeadersTest)  Time elapsed: 0.109 sec  <<< ERROR!
java.lang.NumberFormatException: -2
	at org.eclipse.jetty.util.TypeUtil.parseInt(TypeUtil.java:301)
	at org.eclipse.jetty.http.HttpURI.parse2(HttpURI.java:482)
	at org.eclipse.jetty.http.HttpURI.parse(HttpURI.java:110)
	at org.eclipse.jetty.http.HttpURI.<init>(HttpURI.java:92)
	at org.eclipse.jetty.client.HttpExchange.setURL(HttpExchange.java:352)
	at org.eclipse.jetty.client.HttpHeadersTest.testHttpHeaders(HttpHeadersTest.java:96)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
	at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(Surefi
Comment 6 Greg Wilkins CLA 2010-06-15 22:17:01 EDT
The -2 value indicates that the connector was closed.
There is only a single test in this test harness, so it cannot be that the connector was closed on a previous run and then not started (plus the init method creates a new connector all the time).

The _localport field is well (over?) protected by synchronized, so it can't be a race condition.

I can only conclude that something in server.start() has gone wrong and called connector.close().   I'm now tracing to see if that is possible
Comment 7 Greg Wilkins CLA 2010-06-15 22:31:38 EDT
There should have been console logs like:

2010-06-16 12:29:17.336:INFO::jetty-7.1.5-SNAPSHOT
2010-06-16 12:29:17.338:INFO::Started SelectChannelConnector@0.0.0.0:58272

showing the connector started before the test was run.  Was there?
Comment 8 Joakim Erdfelt CLA 2010-06-16 00:09:44 EDT
Sorry, geez.

I already ran several clean build after reporting this.
Comment 9 Joakim Erdfelt CLA 2011-01-25 13:32:18 EST
Closing this as WORKSFORME as it no longer seems to be happening.