I’m running into an issue where the connection manager broadcast() method is causing an exception when trying to broadcast to a closed connection. The error I’m seeing is:
The WebSocket session [1] has been closed and no method (apart from close()) may be called on a closed session
After this happens, it seems that I need to restart Lucee to get websockets working again.
I’m running Lucee v5.2.2.71 and the websocket extension v2.0.1
Where do you see that error? Is there a stack trace?
Yes, there is a stack trace… see attached
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
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?
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.
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).
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.
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)
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.
Is this unmodified? Line 52 doesn’t match the stacktrace that you posted.
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
Here’s another dump of the exception… this should be in sync with the code.
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
This one might qualify for an issue on github. Can you please open a ticket there and post the stack trace above? Thanks.
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”]
FYI: This has been fixed in version 2.0.2 of the Lucee WebSocket Extension:
Hi I am on tomcat / linux / lucee 5 with websocks 2.0.3
I have 2 issues.
Any help would be greatly appreciated.
Thanks
Chewy
Hi @chewymole , did you ever figure out a solution to this? I think I may be encountering the same issue.