Websocket connection mgr broadcast() exception on closed connections

psarin · January 19, 2022, 3:05pm

In debugging a bit more, I tried:

Upgrading Tomcat to 9.0.56. This did not help.
Determined that error is occurring when client browser navigates away from page and it is trying to close the websocket. If server tries to send a message during this time, the error message occurs.

Any solution from the Lucee side, or would this have to be fixed in the Websocket extension itself?

Here is a stack trace:

lucee.runtime.exp.NativeException: The WebSocket session [3] has been closed and no method (apart from close()) may be called on a closed session
  at org.apache.tomcat.websocket.WsSession.checkState(WsSession.java:1074)
  at org.apache.tomcat.websocket.WsSession.getUserProperties(WsSession.java:982)
  at net.twentyonesolutions.lucee.websocket.WebSocket.getStruct(WebSocket.java:498)
  at net.twentyonesolutions.lucee.websocket.WebSocket.toDumpData(WebSocket.java:561)
  at lucee.runtime.dump.DumpUtil.toDumpData(DumpUtil.java:289)
  at lucee.runtime.dump.DumpUtil.toDumpData(DumpUtil.java:336)
  at lucee.runtime.type.util.StructUtil.toDumpTable(StructUtil.java:169)
  at lucee.runtime.type.StructImpl.toDumpData(StructImpl.java:107)
  at lucee.runtime.dump.DumpUtil.toDumpData(DumpUtil.java:289)
  at lucee.runtime.functions.other.DumpStruct.call(DumpStruct.java:93)
  at lucee.runtime.functions.other.DumpStruct.call(DumpStruct.java:82)
  at dump_cfc$cf.udfCall1(/Dump.cfc:110)
  at dump_cfc$cf.udfCall(/Dump.cfc)
  at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
  at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
  at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:207)
  at lucee.runtime.ComponentImpl._call(ComponentImpl.java:685)
  at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
  at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1930)
  at lucee.runtime.tag.CFTag.cfcStartTag(CFTag.java:384)
  at lucee.runtime.tag.CFTag.doStartTag(CFTag.java:178)
  at writedump_cfm$cf.udfCall(/writeDump.cfm:25)
  at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
  at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
  at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:207)
  at lucee.runtime.functions.system.CFFunction.call(CFFunction.java:109)
  at server.tests.debugws_cfm$cf.call(/orrms/server/tests/debugWS.cfm:18)
  at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1034)
  at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:926)
  at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:217)
  at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44)
  at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2460)
  at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2450)
  at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2421)
  at lucee.runtime.engine.Request.exe(Request.java:45)
  at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1179)
  at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1125)
  at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
  at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
  at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
  at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
  at mod_cfml.core.invoke(core.java:180)
  at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
  at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:433)
  at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
  at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1732)
  at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
  at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
  at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
  at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
  at java.base/java.lang.Thread.run(Unknown Source)
 Caused by: java.lang.IllegalStateException: The WebSocket session [3] has been closed and no method (apart from close()) may be called on a closed session
  ... 63 more

martin · January 19, 2022, 3:39pm

@psarin Do you have logging turned on for websockets? If not, set this ‘debug’ and post some of it back here - it might show something of interest.

I might have come across something similar that was solved by checking if a connection was open in the onUnsubscribe event handler before making any other calls to it.

if(arguments.websocket.isOpen()){
    // do something here
}

psarin · January 21, 2022, 11:55am

Here is the trace from the DEBUG websocket.log that I’m getting (see Issue 1 & Issue 2).

Issue 1


"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:20","websocket","connection 27 enter onError(); java.io.IOException: java.net.SocketTimeoutException
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:327)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:262)
	at org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:816)
	at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:704)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:325)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:254)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendString(WsRemoteEndpointImplBase.java:195)
	at org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:37)
	at net.twentyonesolutions.lucee.websocket.WebSocket.sendText(WebSocket.java:402)
	at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.broadcast(ConnectionManager.java:173)
	at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.call(ConnectionManager.java:393)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.mixins.websocketsmanager_cfc$cf.udfCall(/path/to/server/mixins/WebSocketsManager.cfc:27)
	at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
	at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
	at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
	at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.mixins.messagingmanager_cfc$cf$39.udfCall(/path/to/server/mixins/MessagingManager.cfc:254)
	at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
	at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
	at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
	at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.utils.decisionsupport_cfm$cf.call(/path/to/server/utils/decisionSupport.cfm:17)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1034)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:926)
	at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:217)
	at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44)
	at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2460)
	at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2450)
	at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2421)
	at lucee.runtime.engine.Request.exe(Request.java:45)
	at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1179)
	at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1125)
	at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
	at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at mod_cfml.core.invoke(core.java:180)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1732)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.net.SocketTimeoutException
	at org.apache.tomcat.util.net.NioEndpoint$Poller.timeout(NioEndpoint.java:1070)
	at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:836)
	... 1 more
"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:20","websocket","calling listener.onError()"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:20","websocket","connection 27 enter onClose(); CloseReason: code [1006], reason [Write timeout]"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:20","websocket","calling listener.onClose()"
"WARN","http-nio-8888-exec-2","01/20/2022","14:53:20","websocket","27: java.io.IOException: java.net.SocketTimeoutException: Write timeout"


"DEBUG","cfthread-28206","01/20/2022","14:53:20","websocket","channel channel1NAME broadcasting message to 8 connections"
"DEBUG","cfthread-28208","01/20/2022","14:53:20","websocket","channel channel2NAME broadcasting message to 8 connections"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:21","websocket","channel channel1Name broadcasting message to 8 connections"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:41","websocket","connection 17 enter onError(); java.io.IOException: java.net.SocketTimeoutException
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:327)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:262)
	at org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:816)
	at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:704)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:325)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:254)
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendString(WsRemoteEndpointImplBase.java:195)
	at org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:37)
	at net.twentyonesolutions.lucee.websocket.WebSocket.sendText(WebSocket.java:402)
	at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.broadcast(ConnectionManager.java:173)
	at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.call(ConnectionManager.java:393)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.mixins.websocketsmanager_cfc$cf.udfCall(/path/to/server/mixins/WebSocketsManager.cfc:27)
	at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
	at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
	at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
	at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.mixins.messagingmanager_cfc$cf$39.udfCall(/path/to/server/mixins/MessagingManager.cfc:254)
	at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
	at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
	at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684)
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
	at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911)
	at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
	at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1747)
	at path.to.server.utils.decisionsupport_cfm$cf.call(/path/to/server/utils/decisionSupport.cfm:17)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1034)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:926)
	at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:217)
	at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44)
	at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2460)
	at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2450)
	at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2421)
	at lucee.runtime.engine.Request.exe(Request.java:45)
	at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1179)
	at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1125)
	at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
	at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at mod_cfml.core.invoke(core.java:180)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1732)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.net.SocketTimeoutException
	at org.apache.tomcat.util.net.NioEndpoint$Poller.timeout(NioEndpoint.java:1070)
	at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:836)
	... 1 more
"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:41","websocket","calling listener.onError()"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:41","websocket","connection 17 enter onClose(); CloseReason: code [1006], reason [Write timeout]"
"DEBUG","http-nio-8888-exec-2","01/20/2022","14:53:41","websocket","calling listener.onClose()"
"WARN","http-nio-8888-exec-2","01/20/2022","14:53:41","websocket","17: java.io.IOException: java.net.SocketTimeoutException: Write timeout"

Issue 2

Also getting the following but I think this is to be expected when client closes connection due to some issue?


"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","connection 34 enter onError(); java.io.IOException: An existing connection was forcibly closed by the remote host
	at java.base/sun.nio.ch.SocketDispatcher.read0(Native Method)
	at java.base/sun.nio.ch.SocketDispatcher.read(Unknown Source)
	at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
	at java.base/sun.nio.ch.IOUtil.read(Unknown Source)
	at java.base/sun.nio.ch.IOUtil.read(Unknown Source)
	at java.base/sun.nio.ch.SocketChannelImpl.read(Unknown Source)
	at org.apache.tomcat.util.net.NioChannel.read(NioChannel.java:160)
	at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1326)
	at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1215)
	at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:75)
	at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:183)
	at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:162)
	at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:157)
	at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:60)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:59)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1732)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Unknown Source)
"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onError()"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel2Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel0Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel1Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel2Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel3Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from channel4Name"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onUnsubscribe()"
"INFO","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","34 unsubscribed from main"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","connection 34 enter onClose(); CloseReason: code [1006], reason [An existing connection was forcibly closed by the remote host]"
"DEBUG","http-nio-8888-exec-22","01/20/2022","16:38:39","websocket","calling listener.onClose()"