I ran the test suite 10 times for each connector and for TC 7 and trunk
(yesterdays svn revision).
I got some sporadic failures on my Solaris 10 system using JDK 1.6.0_45
(TC 7) resp. 1.7.0_45 (trunk). A)1) might be a timing issue and B)1)
timing/flushing, so both could well be false positives. A)2)-A)4) are
all websocket tests.
A) TC 7
=======
1) org.apache.catalina.loader.TestWebappClassLoaderMemoryLeak
-------------------------------------------------------------
1 x apr, 3 x bio, 4 x nio
Failure:
Testcase: testTimerThreadLeak took 3.724 sec
FAILED
Timer thread still running
junit.framework.AssertionFailedError: Timer thread still running
at
org.apache.catalina.loader.TestWebappClassLoaderMemoryLeak.testTimerThreadLeak(TestWebappClassLoaderMemoryLeak.java:72)
Log always like:
Dec 16, 2013 8:35:12 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-127.0.0.1-auto-1"]
Dec 16, 2013 8:35:12 PM org.apache.tomcat.util.net.NioSelectorPool
getSharedSelector
INFO: Using a shared selector for servlet write/read
Dec 16, 2013 8:35:12 PM org.apache.catalina.core.StandardService
startInternal
INFO: Starting service Tomcat
Dec 16, 2013 8:35:12 PM org.apache.catalina.core.StandardEngine
startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.X-rXX-dev
Dec 16, 2013 8:35:13 PM org.apache.catalina.util.SessionIdGenerator
createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using
[INSECURE] took [427] milliseconds.
Dec 16, 2013 8:35:13 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-nio-127.0.0.1-auto-1-53581"]
Dec 16, 2013 8:35:14 PM org.apache.catalina.loader.WebappClassLoader
clearReferencesStopTimerThread
SEVERE: The web application [] appears to have started a TimerThread
named [leaked-thread] via the java.util.Timer API but has failed to stop
it. To prevent a memory leak, the t
imer (and hence the associated thread) has been forcibly canceled.
Dec 16, 2013 8:35:14 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-nio-127.0.0.1-auto-1-53581"]
Dec 16, 2013 8:35:14 PM org.apache.catalina.core.StandardService
stopInternal
INFO: Stopping service Tomcat
Dec 16, 2013 8:35:14 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-nio-127.0.0.1-auto-1-53581"]
Dec 16, 2013 8:35:14 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-nio-127.0.0.1-auto-1-53581"]
Next steps: I'll increase the 10ms timeout locally and report back,
whether that helps.
2) org.apache.catalina.websocket.TestWebSocket
----------------------------------------------
2 x bio, 1 x nio
Failure:
Testcase: testBug53339 took 10.309 sec
Caused an ERROR
Read timed out
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at java.net.SocketInputStream.read(SocketInputStream.java:210)
at
org.apache.catalina.websocket.TestWebSocket$WebSocketClient.readMessage(TestWebSocket.java:456)
at
org.apache.catalina.websocket.TestWebSocket$WebSocketClient.access$300(TestWebSocket.java:383)
at
org.apache.catalina.websocket.TestWebSocket.testBug53339(TestWebSocket.java:327)
Log seems not to contain anything relevant:
Dec 16, 2013 9:34:10 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-127.0.0.1-auto-2"]
Dec 16, 2013 9:34:10 PM org.apache.catalina.core.StandardService
startInternal
INFO: Starting service Tomcat
Dec 16, 2013 9:34:10 PM org.apache.catalina.core.StandardEngine
startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.X-rXX-dev
Dec 16, 2013 9:34:10 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-127.0.0.1-auto-2-58747"]
Dec 16, 2013 9:34:20 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-127.0.0.1-auto-2-58747"]
Dec 16, 2013 9:34:21 PM org.apache.catalina.core.StandardService
stopInternal
INFO: Stopping service Tomcat
Next steps: I'll add some debug output locally to WebSocketClient
especially readMessage() and see how far I get.
3) org.apache.tomcat.websocket.TestWsSubprotocols
-------------------------------------------------
1 x bio, 1 x nio
Failure:
Testcase: testWsSubprotocols took 4.005 sec
Caused an ERROR
null
java.lang.NullPointerException
at
org.apache.tomcat.websocket.TestWsSubprotocols.testWsSubprotocols(TestWsSubprotocols.java:89)
Logs: Nothing interesting
Next steps: I'll add some debug logs locally to TestWsSubprotocols and
see how far I get.
4) org.apache.tomcat.websocket.pojo.TestPojoEndpointBase
--------------------------------------------------------
1 x apr
Failure:
Testcase: testOnOpenPojoMethod took 5.853 sec
Caused an ERROR
The HTTP request to initiate the WebSocket connection failed
javax.websocket.DeploymentException: The HTTP request to initiate the
WebSocket connection failed
at
org.apache.tomcat.websocket.WsWebSocketContainer.connectToServer(WsWebSocketContainer.java:373)
at
org.apache.tomcat.websocket.WsWebSocketContainer.connectToServer(WsWebSocketContainer.java:201)
at
org.apache.tomcat.websocket.pojo.TestPojoEndpointBase.testOnOpenPojoMethod(TestPojoEndpointBase.java:106)
Caused by: java.util.concurrent.TimeoutException
at sun.nio.ch.PendingFuture.get(PendingFuture.java:197)
at
org.apache.tomcat.websocket.WsWebSocketContainer.processResponse(WsWebSocketContainer.java:599)
at
org.apache.tomcat.websocket.WsWebSocketContainer.connectToServer(WsWebSocketContainer.java:343)
Logs: Nothing interesting
Next steps: Unclear, seems harder to debug.
B) trunk
========
1) org.apache.catalina.core.TestAsyncContextImpl
------------------------------------------------
1 x apr
Failure:
Testcase: testDispatchErrorWithThreadSingleThenComplete took 8.627 sec
FAILED
Uri: /stage1, Status: 200, Time: 1941
junit.framework.AssertionFailedError: Uri: /stage1, Status: 200, Time: 1941
at
org.apache.catalina.valves.TesterAccessLogValve.validateAccessLog(TesterAccessLogValve.java:87)
at
org.apache.catalina.core.TestAsyncContextImpl.doTestDispatchError(TestAsyncContextImpl.java:979)
at
org.apache.catalina.core.TestAsyncContextImpl.testDispatchErrorWithThreadSingleThenComplete(TestAsyncContextImpl.java:912)
Access log entries:
127.0.0.1 - - [15/Dec/2013:19:17:13 +0100] "GET
/stage1?iter=1&useThread=y HTTP/1.1" 200 125
http-apr-127.0.0.1-auto-1-exec-3 1941
127.0.0.1 - - [15/Dec/2013:19:17:15 +0100] "GET /stage1?iter=1 HTTP/1.1"
200 125 http-apr-127.0.0.1-auto-2-exec-2 510
127.0.0.1 - - [15/Dec/2013:19:17:21 +0100] "GET /start HTTP/1.1" 200 96
http-apr-127.0.0.1-auto-3-exec-3 4004
127.0.0.1 - - [15/Dec/2013:19:17:29 +0100] "GET /start HTTP/1.1" 200 124
http-apr-127.0.0.1-auto-4-exec-5 7009
Next steps: Ill add some milliseconds to the access log and some debug
output to the test to see, whether the access log entry somehow comes to
late (flushing?).
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
