WebSocketSession.close() calls onWebSocketClose() with lock held

[sbordet]

Jetty version
10.0.x

Description
Currently WebSocketSession.close() can be called concurrently and there is no atomic state change to guard against this.

The problem is that calling close() may call application code (onclose event handlers) with the lock held, and that is recipe for problems (for example, CometD 6 deadlocks).

[lachlan-roberts]

@sbordet were you able to reproduce this problem with 10.0.x?

In jetty 10 websocket the only call to onClosed is done in the closeConnection() method which is always guarded with an atomic check to the WebSocketSessionState. So it should only be possible to call onClosed and onError exactly once.

WebSocketSession.close() will not try to call onClosed directly but try to send a close frame, if this fails or we get a close frame in response we try moving the WebSocketSessionState to CLOSED before calling closeConnection() which notifies onClosed.

[sbordet]

@lachlan-roberts see stack trace that shows how WebSocketSession.close() ends up calling onWebSocketClose():

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
	  at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:447)
	  at java.util.concurrent.FutureTask.get(FutureTask.java:190)
	  at org.cometd.javascript.JavaScript.result(JavaScript.java:175)
	  at org.cometd.javascript.JavaScript.submitTask(JavaScript.java:143)
	  at org.cometd.javascript.JavaScript.evaluate(JavaScript.java:138)
	  at org.cometd.javascript.WebSocketConnection.onWebSocketClose(WebSocketConnection.java:110)
	  at java.lang.invoke.LambdaForm$DMH.2011695710.invokeVirtual(LambdaForm$DMH:-1)
	  at java.lang.invoke.LambdaForm$MH.1019290902.invoke(LambdaForm$MH:-1)
	  at java.lang.invoke.LambdaForm$MH.1013620810.invoke_MT(LambdaForm$MH:-1)
	  at org.eclipse.jetty.websocket.common.JettyWebSocketFrameHandler.onClosed(JettyWebSocketFrameHandler.java:293)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.lambda$closeConnection$3(WebSocketCoreSession.java:374)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession$$Lambda$347.197449185.run(Unknown Source:-1)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.handle(WebSocketCoreSession.java:107)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.closeConnection(WebSocketCoreSession.java:374)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.lambda$sendFrame$7(WebSocketCoreSession.java:554)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession$$Lambda$345.1005245720.run(Unknown Source:-1)
	  at org.eclipse.jetty.util.Callback$3.succeeded(Callback.java:129)
	  at org.eclipse.jetty.websocket.core.internal.TransformingFlusher.notifyCallbackSuccess(TransformingFlusher.java:156)
	  at org.eclipse.jetty.websocket.core.internal.TransformingFlusher$Flusher.process(TransformingFlusher.java:116)
	  at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:237)
	  at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:219)
	  at org.eclipse.jetty.websocket.core.internal.TransformingFlusher.sendFrame(TransformingFlusher.java:80)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.sendFrame(WebSocketCoreSession.java:557)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.close(WebSocketCoreSession.java:316)
	  at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.close(WebSocketCoreSession.java:311)
	  at org.eclipse.jetty.websocket.common.JettyWebSocketRemoteEndpoint.close(JettyWebSocketRemoteEndpoint.java:79)
	  at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:70)
	  at org.eclipse.jetty.websocket.common.SessionTracker.doStop(SessionTracker.java:57)

[sbordet]

CometD 6 failing test is CometDWebSocketServerProtocolTest.testClientWithWebSocketProtocolServerWithWebSocketProtocol()

[gregw]

@sbordet what lock is being held? We can't see any core locks in that stack trace?

[sbordet]

@gregw the lock being held is the one from JettyWebSocketRemoteEndpoint.close(), a SharedBlockingCallback.

[gregw]

Just for the sake of clarity in this issue... as discussed on a hangout, the problem is not a held lock, but an allocated SharedBlockingCallback. The second call waits or the allocated callback to be returned (auto closed), but that never happens because the first call is the one reentrantly making the second call and thus will not complete as it is waiting on itself.

The solution may be just to not used a shared callback

There is also a question as why block() is not called?