Re: Random Comet unit test failures

2011-11-23 Thread Rainer Jung

On 23.11.2011 08:14, Konstantin Kolinko wrote:

2011/11/23 Mark Thomasma...@apache.org:

I have done a little bit of digging on this as the current 7.0.x trunk
fails frequently enough on my windows box that I can repeat the failure
often enough.

I have got as far as discovering that the request.getAvailable() test on
line 308 of the CoyoteAdapter returns zero whenever the test fails.

While, I haven't figured out how this leads to the failure yet, I
thought the info may help others make some progress on this.

There is clearly a timing / threading issue here but I haven't found it yet.



What failure are you pursuing?

The following one occurs frequently on Gump/buildbot:
[[[
Testcase: testCometConnectorStop took 4.078 sec
FAILED
Comet END event not received
junit.framework.AssertionFailedError: Comet END event not received
at 
org.apache.catalina.comet.TestCometProcessor.testCometConnectorStop(TestCometProcessor.java:293)
]]]


... or the 8 Bytes received instead of two separate 4 Bytes messages:

Testcase: testSimpleCometClient took 9.304 sec
FAILED
expected:Client: READ: [4] bytes but was:Client: READ: [8] bytes
junit.framework.AssertionFailedError: expected:Client: READ: [4] bytes 
but was:Client: READ: [8] bytes
at 
org.apache.catalina.comet.TestCometProcessor.doSimpleCometTest(TestCometProcessor.java:196)
at 
org.apache.catalina.comet.TestCometProcessor.testSimpleCometClient(TestCometProcessor.java:121)


That is the one I can easily reproduce running NIO and AFAICT it occurs 
before the exceptions logged.



In the main stdout file there occasionally are also a lot of NPE like
[[[
 [junit] Nov 23, 2011 3:37:25 AM
org.apache.coyote.http11.AbstractHttp11Processor process
 [junit] SEVERE: Error processing request
 [junit] java.lang.NullPointerException
 [junit]at
org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:126)
 [junit]at
org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:175)
 [junit]at
org.apache.coyote.http11.InternalNioOutputBuffer.writeToSocket(InternalNioOutputBuffer.java:170)
 [junit]at
org.apache.coyote.http11.InternalNioOutputBuffer.flushBuffer(InternalNioOutputBuffer.java:249)
 [junit]at
org.apache.coyote.http11.InternalNioOutputBuffer.endRequest(InternalNioOutputBuffer.java:128)
 [junit]at
org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:741)
 [junit]at org.apache.coyote.Response.action(Response.java:170)
 [junit]at org.apache.coyote.Response.finish(Response.java:276)
 [junit]at
org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:288)
 [junit]at
org.apache.catalina.connector.Response.finishResponse(Response.java:507)
 [junit]at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:434)
 [junit]at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
 [junit]at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539)
 [junit]at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1571)
 [junit]at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
 [junit]at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
 [junit]at java.lang.Thread.run(Thread.java:636)


 [junit] Nov 23, 2011 3:37:25 AM
org.apache.catalina.connector.CoyoteAdapter log
 [junit] WARNING: Exception while attempting to add an entry to the
access log
 [junit] java.lang.NullPointerException
 [junit]at
org.apache.catalina.connector.CoyoteAdapter.log(CoyoteAdapter.java:511)
 [junit]at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1007)
 [junit]at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539)
 [junit]at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1571)
 [junit]at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
 [junit]at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
 [junit]at java.lang.Thread.run(Thread.java:636)
]]]

The above one is from
http://vmgump.apache.org/gump/public/tomcat-7.0.x/tomcat-tc7.0.x-test/gump_work/build_tomcat-7.0.x_tomcat-tc7.0.x-test.txt


-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



Re: Random Comet unit test failures

2011-11-23 Thread Mark Thomas
On 23/11/2011 08:19, Rainer Jung wrote:
 On 23.11.2011 08:14, Konstantin Kolinko wrote:
 2011/11/23 Mark Thomasma...@apache.org:
 I have done a little bit of digging on this as the current 7.0.x trunk
 fails frequently enough on my windows box that I can repeat the failure
 often enough.

 I have got as far as discovering that the request.getAvailable() test on
 line 308 of the CoyoteAdapter returns zero whenever the test fails.

 While, I haven't figured out how this leads to the failure yet, I
 thought the info may help others make some progress on this.

 There is clearly a timing / threading issue here but I haven't found
 it yet.


 What failure are you pursuing?

 The following one occurs frequently on Gump/buildbot:
 [[[
 Testcase: testCometConnectorStop took 4.078 sec
 FAILED
 Comet END event not received
 junit.framework.AssertionFailedError: Comet END event not received
 at
 org.apache.catalina.comet.TestCometProcessor.testCometConnectorStop(TestCometProcessor.java:293)

 ]]]
 
 ... or the 8 Bytes received instead of two separate 4 Bytes messages:
 
 Testcase: testSimpleCometClient took 9.304 sec
 FAILED
 expected:Client: READ: [4] bytes but was:Client: READ: [8] bytes
 junit.framework.AssertionFailedError: expected:Client: READ: [4] bytes
 but was:Client: READ: [8] bytes
 at
 org.apache.catalina.comet.TestCometProcessor.doSimpleCometTest(TestCometProcessor.java:196)
 
 at
 org.apache.catalina.comet.TestCometProcessor.testSimpleCometClient(TestCometProcessor.java:121)
 
 
 That is the one I can easily reproduce running NIO and AFAICT it occurs
 before the exceptions logged.

This one. The 8 bytes rather than 2 * 4 bytes.

Mark

-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



Random Comet unit test failures

2011-11-22 Thread Mark Thomas
I have done a little bit of digging on this as the current 7.0.x trunk
fails frequently enough on my windows box that I can repeat the failure
often enough.

I have got as far as discovering that the request.getAvailable() test on
line 308 of the CoyoteAdapter returns zero whenever the test fails.

While, I haven't figured out how this leads to the failure yet, I
thought the info may help others make some progress on this.

There is clearly a timing / threading issue here but I haven't found it yet.

Mark

-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



Re: Random Comet unit test failures

2011-11-22 Thread Konstantin Kolinko
2011/11/23 Mark Thomas ma...@apache.org:
 I have done a little bit of digging on this as the current 7.0.x trunk
 fails frequently enough on my windows box that I can repeat the failure
 often enough.

 I have got as far as discovering that the request.getAvailable() test on
 line 308 of the CoyoteAdapter returns zero whenever the test fails.

 While, I haven't figured out how this leads to the failure yet, I
 thought the info may help others make some progress on this.

 There is clearly a timing / threading issue here but I haven't found it yet.


What failure are you pursuing?

The following one occurs frequently on Gump/buildbot:
[[[
Testcase: testCometConnectorStop took 4.078 sec
FAILED
Comet END event not received
junit.framework.AssertionFailedError: Comet END event not received
at 
org.apache.catalina.comet.TestCometProcessor.testCometConnectorStop(TestCometProcessor.java:293)
]]]


In the main stdout file there occasionally are also a lot of NPE like
[[[
[junit] Nov 23, 2011 3:37:25 AM
org.apache.coyote.http11.AbstractHttp11Processor process
[junit] SEVERE: Error processing request
[junit] java.lang.NullPointerException
[junit] at
org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:126)
[junit] at
org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:175)
[junit] at
org.apache.coyote.http11.InternalNioOutputBuffer.writeToSocket(InternalNioOutputBuffer.java:170)
[junit] at
org.apache.coyote.http11.InternalNioOutputBuffer.flushBuffer(InternalNioOutputBuffer.java:249)
[junit] at
org.apache.coyote.http11.InternalNioOutputBuffer.endRequest(InternalNioOutputBuffer.java:128)
[junit] at
org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:741)
[junit] at org.apache.coyote.Response.action(Response.java:170)
[junit] at org.apache.coyote.Response.finish(Response.java:276)
[junit] at
org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:288)
[junit] at
org.apache.catalina.connector.Response.finishResponse(Response.java:507)
[junit] at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:434)
[junit] at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
[junit] at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539)
[junit] at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1571)
[junit] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit] at java.lang.Thread.run(Thread.java:636)


[junit] Nov 23, 2011 3:37:25 AM
org.apache.catalina.connector.CoyoteAdapter log
[junit] WARNING: Exception while attempting to add an entry to the
access log
[junit] java.lang.NullPointerException
[junit] at
org.apache.catalina.connector.CoyoteAdapter.log(CoyoteAdapter.java:511)
[junit] at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1007)
[junit] at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539)
[junit] at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1571)
[junit] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit] at java.lang.Thread.run(Thread.java:636)
]]]

The above one is from
http://vmgump.apache.org/gump/public/tomcat-7.0.x/tomcat-tc7.0.x-test/gump_work/build_tomcat-7.0.x_tomcat-tc7.0.x-test.txt


Best regards,
Konstantin Kolinko

-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org