Websocket connection mgr broadcast() exception on closed connections

hacking extensions
4

lucee.runtime.exp.NativeException: The WebSocket session [0] 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:782) at org.apache.tomcat.websocket.WsSession.getUserProperties(WsSession.java:727) at net.twentyonesolutions.lucee.websocket.WebSocket.getChannels(WebSocket.java:456) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.unsubscribeAll(ConnectionManager.java:193) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.broadcast(ConnectionManager.java:178) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.call(ConnectionManager.java:393) at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:758) at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1693) at chatlistener_cfc$cf.udfCall(/ChatListener.cfc:109) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:107) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:355) at lucee.runtime.type.UDFImpl.call(UDFImpl.java:226) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:662) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:580) at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1918) at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:758) at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1693) at chatlistener_cfc$cf.udfCall(/ChatListener.cfc:52) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:107) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:355) at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:212) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:663) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:580) at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1935) at net.twentyonesolutions.lucee.app.LuceeAppListener.invokeWithNamedArgs(LuceeAppListener.java:118) at net.twentyonesolutions.lucee.websocket.WebsocketUtil.invokeListenerMethodWithNamedArgs(WebsocketUtil.java:77) at net.twentyonesolutions.lucee.websocket.WebsocketUtil.invokeListenerMethodWithNamedArgs(WebsocketUtil.java:103) at net.twentyonesolutions.lucee.websocket.LuceeEndpoint.onClose(LuceeEndpoint.java:119) at org.apache.tomcat.websocket.WsSession.fireEndpointOnClose(WsSession.java:542) at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:491) at org.apache.tomcat.websocket.WsSession.close(WsSession.java:455) at org.apache.tomcat.websocket.WsSession.close(WsSession.java:449) at net.twentyonesolutions.lucee.websocket.LuceeEndpoint.onOpen(LuceeEndpoint.java:68) at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:127) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:705) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476) 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.IllegalStateException: The WebSocket session [0] has been closed and no method (apart from close()) may be called on a closed session ... 41 more

5

Weird… even after restarting Lucee, it seems like the websocket extension is still trying to broadcast to the same closed connections. In another post, you referred to restarting the servlet container… what do you mean by that? I assumed you meant restart Lucee… is there something else that needs to be restarted to completely reset the websocket extension?

6

The WebSocket connections run in the Servlet Container (Tomcat in your case), completely outside of Lucee, in a way they run side-by-side with Lucee.

Restarting Lucee from the Admin, for example, is therefore not enough. You must restart Tomcat (the Servlet Container).

If you did that and the issue persist, then the Web Server proxy (in your case IIS via ARR) might be causing the issue.

7

This is happening on my dev environment, and I’m running this app directly through Lucee’s tomcat port (8888). How do I restart Tomcat? I assumed that Tomcat starts/stops when Lucee starts and stops. I’m using the Tomcat that is packaged inside the lucee directory (Windows).

8

Can you post the code of your function in ChatListener.cfc (the one that contains line 109)? Mask any sensitive information if needed, but try to keep the rest unmodified.

9

Nothing sensitive in this… it’s just a modified version of your sample chat application that I use for testing websockets.

ChatListener.cfc (4.9 KB)

10

I’m sorry but I’m not familiar with that setup as I always install manually. Post a screenshot of what you’re doing and perhaps someone (or I) can help.

11

Is this unmodified? Line 52 doesn’t match the stacktrace that you posted.

12

Yes, it should be the same, but perhaps if Tomcat wasn’t restarted when I restarted Lucee, then maybe it’s out of sync. I guess I still need to figure out how to make sure tomcat gets restarted.

https://lucee.daemonite.io/t/how-do-i-restart-tomcat-on-windows-under-default-lucee-setup/2697

13

Here’s another dump of the exception… this should be in sync with the code.

error-2017-08-25-11-14-29-2046699486860768.html (98.3 KB)

14

lucee.runtime.exp.NativeException: The WebSocket session [1] 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:782) at org.apache.tomcat.websocket.WsSession.getUserProperties(WsSession.java:727) at net.twentyonesolutions.lucee.websocket.WebSocket.getChannels(WebSocket.java:456) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.unsubscribeAll(ConnectionManager.java:193) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.broadcast(ConnectionManager.java:178) at net.twentyonesolutions.lucee.websocket.connections.ConnectionManager.call(ConnectionManager.java:393) at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:758) at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1693) at chatlistener_cfc$cf.udfCall(/ChatListener.cfc:114) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:107) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:355) at lucee.runtime.type.UDFImpl.call(UDFImpl.java:226) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:662) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:580) at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1918) at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:758) at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1693) at chatlistener_cfc$cf.udfCall(/ChatListener.cfc:29) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:107) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:355) at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:212) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:663) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:580) at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1935) at net.twentyonesolutions.lucee.app.LuceeAppListener.invokeWithNamedArgs(LuceeAppListener.java:118) at net.twentyonesolutions.lucee.websocket.WebsocketUtil.invokeListenerMethodWithNamedArgs(WebsocketUtil.java:77) at net.twentyonesolutions.lucee.websocket.WebsocketUtil.invokeListenerMethodWithNamedArgs(WebsocketUtil.java:103) at net.twentyonesolutions.lucee.websocket.LuceeEndpoint.onOpen(LuceeEndpoint.java:57) at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:127) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:705) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476) 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.IllegalStateException: The WebSocket session [1] has been closed and no method (apart from close()) may be called on a closed session ... 36 more

15

This one might qualify for an issue on github. Can you please open a ticket there and post the stack trace above? Thanks.

16
17

Looks like there may be something that’s not cleaned up after restarting Lucee on Windows (using the Lucee Service). This could explain why I get the same broadcast error, even after restarting Lucee. Here’s the tail of my Tomcat catalina log after stopping the Lucee Service:

27-Aug-2017 15:16:11.005 INFO [Thread-111] org.apache.catalina.core.StandardService.stopInternal Stopping service Catalina
27-Aug-2017 15:16:11.009 INFO [local.chat.com-startStop-2] org.apache.catalina.core.ApplicationContext.log org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
27-Aug-2017 15:16:11.068 WARNING [local.chat.com-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixDispatchQueue] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
org.apache.felix.framework.util.EventDispatcher.run(EventDispatcher.java:1118)
org.apache.felix.framework.util.EventDispatcher.access$000(EventDispatcher.java:55)
org.apache.felix.framework.util.EventDispatcher$1.run(EventDispatcher.java:102)
java.lang.Thread.run(Thread.java:745)
27-Aug-2017 15:16:11.069 WARNING [local.chat.com-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixFrameworkWiring] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
org.apache.felix.framework.FrameworkWiringImpl.run(FrameworkWiringImpl.java:172)
java.lang.Thread.run(Thread.java:745)
27-Aug-2017 15:16:11.070 WARNING [local.chat.com-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixStartLevel] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:283)
java.lang.Thread.run(Thread.java:745)
27-Aug-2017 15:16:11.143 INFO [Thread-111] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler [“http-nio-8888”]
27-Aug-2017 15:16:11.143 INFO [Thread-111] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler [“ajp-nio-8009”]

18

FYI: This has been fixed in version 2.0.2 of the Lucee WebSocket Extension:

1 Like
19

Hi I am on tomcat / linux / lucee 5 with websocks 2.0.3
I have 2 issues.

  1. how do you stop users from subscribing to the same channel multiple times?
  2. when this happens, the older sessions will cause the error above because they have timed out, no messages can be sent to the live sessions in that same channel. There is also no way (that i have found) to unsubscribe them.

Any help would be greatly appreciated.

Thanks
Chewy

20

Hi @chewymole , did you ever figure out a solution to this? I think I may be encountering the same issue.

21

In debugging a bit more, I tried:

  1. Upgrading Tomcat to 9.0.56. This did not help.
  2. 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
22

@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
}
1 Like
23

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()"