Bug 61773

Summary: When more than 10000 times of HTTPS websocket, Tomcat cannot respond to requesting HTTPS requests
Product: Tomcat 8 Reporter: Xiaojin Zhang <zhangxj>
Component: WebSocketAssignee: Tomcat Developers Mailing List <dev>
Status: RESOLVED FIXED    
Severity: normal    
Priority: P2    
Version: 8.0.47   
Target Milestone: ----   
Hardware: All   
OS: Linux   
Attachments: Attachment is the test code and the server.xml

Description Xiaojin Zhang 2017-11-17 04:57:30 UTC
Created attachment 35534 [details]
Attachment is the test code and the server.xml

When more than 10000 times of HTTPS websocket, Tomcat cannot respond to requesting HTTPS requests.

By checking the Nio2Endpoint code, blocking when the number of requests will exceed 10000. Maybe the abnormal release of Https leads to this problem.

I use Tomcat's chat examples to test it. Only HTTPs has problems, and HTTP is normal. Tomcat 8.5.23 is also normal.
Comment 1 Xiaojin Zhang 2017-11-17 05:29:33 UTC
Blocked at Nio2Endpoint$Acceptor.countUpOrAwaitConnection.Thread information below.

"http-nio2-8443-Acceptor-0" #182 daemon prio=5 os_prio=0 tid=0x00007fe20c1ea000 nid=0xe85 waiting on condition [0x00007fe125be0000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000a70c0578> (a org.apache.tomcat.util.threads.LimitLatch$Sync)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
	at org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait(LimitLatch.java)
	at org.apache.tomcat.util.net.AbstractEndpoint.countUpOrAwaitConnection(AbstractEndpoint.java)
	at org.apache.tomcat.util.net.Nio2Endpoint$Acceptor.run(Nio2Endpoint.java:715)
	at java.lang.Thread.run(Thread.java:745)
Comment 2 Remy Maucherat 2017-11-17 06:02:21 UTC
Please use the user list http://tomcat.apache.org/lists.html#tomcat-users to get support on this issue.
Comment 3 Xiaojin Zhang 2017-11-18 07:04:38 UTC
After further testing, it is found that when Connector is configured with Http2NioProtocol, Websocket closes and AbstractEndpoint.countDownConnection cannot be called.
Details of closing Websocket connection are as follows:
1, when the WebSocket is closed by the client, it first calls the Nio2Channel.close method. This method calls SocketChannel.close and calls Nio2Channel.isOpen back to false

2, the last call to the Nio2Endpoint.closeSocket method, the release of Socket. This method is called AbstractEndpoint.countDownConnection if Nio2Channel.isOpen returns true, but the first step is to call the SocketChannel.close method, it returns false, leading to the call to AbstractEndpoint.countDownConnection, the number of connections appear unable to release, and cannot receive the new request when opened Websocket over 10000.

So, I guess the problem is on the Nio2Endpoint.closeSocket implementation.

Please see logs for testing.



Step 1 log:

-----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------+
|           STACK | thread_name="http-nio2-8080-exec-5" thread_id=0x10;is_daemon=true;priority=5;                                                                          |
|                 |     @org.apache.tomcat.util.net.Nio2Channel.isOpen(Nio2Channel.java:96)                                                                                |
|                 |         at org.apache.tomcat.util.net.Nio2Channel.close(Nio2Channel.java:84)                                                                           |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletOutputStream.doClose(Nio2ServletOutputStream.java:196)                                          |
|                 |         at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.close(AbstractServletOutputStream.java:140)                                    |
|                 |         at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doClose(WsRemoteEndpointImplServer.java:139)                                  |
|                 |         at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.close(WsRemoteEndpointImplBase.java:667)                                               |
|                 |         at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsWriteListener.onError(WsHttpUpgradeHandler.java:234)                              |
|                 |         at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.onError(AbstractServletOutputStream.java:239)                                  |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletOutputStream$1.failed(Nio2ServletOutputStream.java:74)                                          |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletOutputStream$1.failed(Nio2ServletOutputStream.java:51)                                          |
|                 |         at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:128)                                                                                        |
|                 |         at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)                                                                                           |
|                 |         at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:736)                                          |
|                 |         at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382)                                                      |
|                 |         at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:399)                                                      |
|                 |         at org.apache.tomcat.util.net.Nio2Channel.write(Nio2Channel.java:161)                                                                          |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletOutputStream.doWriteInternal(Nio2ServletOutputStream.java:153)                                  |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletOutputStream.doWrite(Nio2ServletOutputStream.java:97)                                           |
|                 |         at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInternal(AbstractServletOutputStream.java:165)                            |
|                 |         at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(AbstractServletOutputStream.java:132)                                    |
|                 |         at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWritePossible(WsRemoteEndpointImplServer.java:98)                           |
|                 |         at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doWrite(WsRemoteEndpointImplServer.java:79)                                   |
|                 |         at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:453)                                    |
|                 |         at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsRemoteEndpointImplBase.java:341)                                        |
|                 |         at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:273)                                   |
|                 |         at org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:600)                                                                  |
|                 |         at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:490)                                                                           |
|                 |         at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.onError(WsHttpUpgradeHandler.java:149)                                              |
|                 |         at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(WsHttpUpgradeHandler.java:47)                                            |
|                 |         at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onError(WsHttpUpgradeHandler.java:206)                               |
|                 |         at org.apache.coyote.http11.upgrade.AbstractServletInputStream.onError(AbstractServletInputStream.java:216)                                    |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletInputStream$1.failed(Nio2ServletInputStream.java:82)                                            |
|                 |         at org.apache.coyote.http11.upgrade.Nio2ServletInputStream$1.failed(Nio2ServletInputStream.java:51)                                            |
|                 |         at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:128)                                                                                        |
|                 |         at sun.nio.ch.Invoker$2.run(Invoker.java:218)                                                                                                  |
|                 |         at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)                                                        |
|                 |         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:-1)                                                          |
|                 |         at java.lang.Thread.run(Thread.java:748)                                                                                                   

Step 2 log:
+-----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------+
|           STACK | thread_name="http-nio2-8080-exec-8" thread_id=0x13;is_daemon=true;priority=5;                                                                          |
|                 |     @org.apache.tomcat.util.net.Nio2Channel.isOpen(Nio2Channel.java:96)                                                                                |
|                 |         at org.apache.tomcat.util.net.Nio2Endpoint.closeSocket(Nio2Endpoint.java:649)                                                                  |
|                 |         at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1102)                                                       |
|                 |         at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.run(Nio2Endpoint.java:1056)                                                         |
|                 |         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:-1)                                                          |
|                 |         at java.lang.Thread.run(Thread.java:748)                                                                                                       |
+-----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------+
Comment 4 Mark Thomas 2017-11-21 15:01:26 UTC
Thanks for the additional information.

I have been able to reproduce this with NIO2 with both http and https connections. I did this by connecting to the WebSocket chat example and then closing the browser while monitoring the current connection count via JMX. For every new chat Window, the connection count increased by 2 but only decreased by one when the window closed.

This only affects NIO2 on Tomcat 8.0.x.

This has been fixed in 8.0.x trunk and will be included in 8.0.48 onwards.