Mark I am seing regular failures in TestPojoEndpointBase in trunk where the socket is not being closed (see attached log). I’ve not dug in yet but this has started since r1660358 and may be related to recent NIO changes (maybe r1660582?).
Cheers Jeremy
Testsuite: org.apache.tomcat.websocket.pojo.TestPojoEndpointBase
Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 10.992 sec
------------- Standard Error -----------------
19-Feb-2015 07:12:20.251 INFO [main]
org.apache.catalina.startup.LoggingBaseTest.setUp Starting test case
[testBug54716]
19-Feb-2015 07:12:20.680 INFO [main] org.apache.coyote.AbstractProtocol.init
Initializing ProtocolHandler ["http-nio-127.0.0.1-auto-1"]
19-Feb-2015 07:12:20.703 INFO [main]
org.apache.catalina.core.StandardService.startInternal Starting service Tomcat
19-Feb-2015 07:12:20.703 INFO [main]
org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine:
Apache Tomcat/9.0.0-dev
19-Feb-2015 07:12:20.810 INFO [main] org.apache.coyote.AbstractProtocol.start
Starting ProtocolHandler ["http-nio-127.0.0.1-auto-1-49282"]
19-Feb-2015 07:12:20.993 SEVERE [http-nio-127.0.0.1-auto-1-exec-1]
org.apache.tomcat.websocket.pojo.PojoEndpointBase.onError No error handling
configured for [org.apache.tomcat.websocket.pojo.TestPojoEndpointBase$Bug54716]
and the following error occurred
java.lang.RuntimeException
at
org.apache.tomcat.websocket.pojo.TestPojoEndpointBase$Bug54716.onOpen(TestPojoEndpointBase.java:131)
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:483)
at
org.apache.tomcat.websocket.pojo.PojoEndpointBase.doOnOpen(PojoEndpointBase.java:66)
at
org.apache.tomcat.websocket.pojo.PojoEndpointServer.onOpen(PojoEndpointServer.java:70)
at
org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:138)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:691)
at
org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:181)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
19-Feb-2015 07:12:25.997 INFO [main] org.apache.coyote.AbstractProtocol.pause
Pausing ProtocolHandler ["http-nio-127.0.0.1-auto-1-49282"]
19-Feb-2015 07:12:26.055 INFO [main]
org.apache.catalina.core.StandardService.stopInternal Stopping service Tomcat
19-Feb-2015 07:12:26.059 WARNING [localhost-startStop-1]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web
application [ROOT] appears to have started a thread named
[http-nio-127.0.0.1-auto-1-exec-1] but has failed to stop it. This is very
likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
org.apache.tomcat.websocket.FutureToSendHandler.get(FutureToSendHandler.java:93)
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:275)
org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:570)
org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:478)
org.apache.tomcat.websocket.WsSession.close(WsSession.java:445)
org.apache.tomcat.websocket.WsSession.close(WsSession.java:439)
org.apache.tomcat.websocket.pojo.PojoEndpointBase.handleOnOpenOrCloseError(PojoEndpointBase.java:96)
org.apache.tomcat.websocket.pojo.PojoEndpointBase.doOnOpen(PojoEndpointBase.java:79)
org.apache.tomcat.websocket.pojo.PojoEndpointServer.onOpen(PojoEndpointServer.java:70)
org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:138)
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:691)
org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:181)
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
java.lang.Thread.run(Thread.java:745)
19-Feb-2015 07:12:26.062 INFO [main] org.apache.coyote.AbstractProtocol.stop
Stopping ProtocolHandler ["http-nio-127.0.0.1-auto-1-49282"]
19-Feb-2015 07:12:26.064 SEVERE [http-nio-127.0.0.1-auto-1-exec-1]
org.apache.tomcat.websocket.pojo.PojoEndpointBase.onError No error handling
configured for [org.apache.tomcat.websocket.pojo.TestPojoEndpointBase$Bug54716]
and the following error occurred
java.io.IOException: java.lang.InterruptedException
at
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:282)
at
org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:570)
at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:478)
at org.apache.tomcat.websocket.WsSession.close(WsSession.java:445)
at org.apache.tomcat.websocket.WsSession.close(WsSession.java:439)
at
org.apache.tomcat.websocket.pojo.PojoEndpointBase.handleOnOpenOrCloseError(PojoEndpointBase.java:96)
at
org.apache.tomcat.websocket.pojo.PojoEndpointBase.doOnOpen(PojoEndpointBase.java:79)
at
org.apache.tomcat.websocket.pojo.PojoEndpointServer.onOpen(PojoEndpointServer.java:70)
at
org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:138)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:691)
at
org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:181)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.InterruptedException
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
at
org.apache.tomcat.websocket.FutureToSendHandler.get(FutureToSendHandler.java:93)
at
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:275)
... 16 more
19-Feb-2015 07:12:26.065 INFO [main] org.apache.coyote.AbstractProtocol.destroy
Destroying ProtocolHandler ["http-nio-127.0.0.1-auto-1-49282"]
19-Feb-2015 07:12:26.074 INFO [main]
org.apache.catalina.startup.LoggingBaseTest.setUp Starting test case
[testOnOpenPojoMethod]
19-Feb-2015 07:12:26.076 INFO [main] org.apache.coyote.AbstractProtocol.init
Initializing ProtocolHandler ["http-nio-127.0.0.1-auto-2"]
19-Feb-2015 07:12:26.077 INFO [main]
org.apache.catalina.core.StandardService.startInternal Starting service Tomcat
19-Feb-2015 07:12:26.077 INFO [main]
org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine:
Apache Tomcat/9.0.0-dev
19-Feb-2015 07:12:26.084 INFO [main] org.apache.coyote.AbstractProtocol.start
Starting ProtocolHandler ["http-nio-127.0.0.1-auto-2-49285"]
19-Feb-2015 07:12:31.090 INFO [main] org.apache.coyote.AbstractProtocol.pause
Pausing ProtocolHandler ["http-nio-127.0.0.1-auto-2-49285"]
19-Feb-2015 07:12:31.145 INFO [main]
org.apache.catalina.core.StandardService.stopInternal Stopping service Tomcat
19-Feb-2015 07:12:31.148 INFO [main] org.apache.coyote.AbstractProtocol.stop
Stopping ProtocolHandler ["http-nio-127.0.0.1-auto-2-49285"]
19-Feb-2015 07:12:31.207 INFO [main] org.apache.coyote.AbstractProtocol.destroy
Destroying ProtocolHandler ["http-nio-127.0.0.1-auto-2-49285"]
------------- ---------------- ---------------
Testcase: testBug54716 took 5.841 sec
FAILED
Server failed to close connection
junit.framework.AssertionFailedError: Server failed to close connection
at
org.apache.tomcat.websocket.pojo.TestPojoEndpointBase.testBug54716(TestPojoEndpointBase.java:74)
Testcase: testOnOpenPojoMethod took 5.135 sec
signature.asc
Description: Message signed with OpenPGP using GPGMail
