WebSockets closed abruptly when using HTTP/2

[mperktold]

Jetty version(s)
10.0.9

Java version/vendor (use: java -version)
openjdk version "17.0.2" 2022-01-18
OpenJDK Runtime Environment Temurin-17.0.2+8 (build 17.0.2+8)
OpenJDK 64-Bit Server VM Temurin-17.0.2+8 (build 17.0.2+8, mixed mode, sharing)

OS type/version
Windows 10

Description

I was investigating our Vaadin application when I noticed warnings regarding websockets being closed abruptly in the browser console.
The websocket is closed every time the idle timeout expires and reconnected afterwards, so far so good. But apparently the closing happens in an abrupt way.

This only happens when using HTTP/2. In that case, before the websocket expires, the HTTP2Session expires. When notifying the application about it, the following exception is thrown:

java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout 300000 ms elapsed
	at org.eclipse.jetty.http2.HTTP2StreamEndPoint$Entry.ioFailure(HTTP2StreamEndPoint.java:625)
	at org.eclipse.jetty.http2.HTTP2StreamEndPoint.fill(HTTP2StreamEndPoint.java:206)
	at org.eclipse.jetty.websocket.core.internal.WebSocketConnection.fillAndParse(WebSocketConnection.java:474)
	at org.eclipse.jetty.websocket.core.internal.WebSocketConnection.onFillable(WebSocketConnection.java:340)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319)
	at org.eclipse.jetty.http2.HTTP2StreamEndPoint.process(HTTP2StreamEndPoint.java:587)
	at org.eclipse.jetty.http2.HTTP2StreamEndPoint.offerFailure(HTTP2StreamEndPoint.java:565)
	at org.eclipse.jetty.http2.server.ServerHTTP2StreamEndPoint.onTimeout(ServerHTTP2StreamEndPoint.java:56)
	at org.eclipse.jetty.http2.server.HTTP2ServerConnection.onStreamTimeout(HTTP2ServerConnection.java:180)
	at org.eclipse.jetty.http2.server.HTTP2ServerConnectionFactory$HTTPServerSessionListener.onIdleTimeout(HTTP2ServerConnectionFactory.java:183)
	at org.eclipse.jetty.http2.HTTP2Stream.notifyIdleTimeout(HTTP2Stream.java:863)
	at org.eclipse.jetty.http2.HTTP2Stream.onIdleExpired(HTTP2Stream.java:326)
	at org.eclipse.jetty.http2.HTTP2Session$StreamTimeouts.onExpired(HTTP2Session.java:2357)
	at org.eclipse.jetty.http2.HTTP2Session$StreamTimeouts.onExpired(HTTP2Session.java:2341)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:105)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:191)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:293)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.TimeoutException: Idle timeout 300000 ms elapsed
	... 12 more

This exception is catched and passed to WebSocketCoreSession#processConnectionError. There, the TimeoutException wrapped inside an IOException is not recognized, so no frame is sent and the session is closed.

Then, the WebSocketConnection is expired. This also ends up in WebSocketCoreSession#processConnectionError, this time with a WebSocketTimeoutException, which is recognized and mapped to CloseStatus.SHUTDOWN. Therefore, Jetty tries to send a corresponding close frame, but fails because the session is already closed due to the first exception. Another exception is thrown to report this failure:

java.nio.channels.ClosedChannelException
	at org.eclipse.jetty.websocket.core.internal.WebSocketSessionState.onOutgoingFrame(WebSocketSessionState.java:184)
	at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.sendFrame(WebSocketCoreSession.java:513)
	at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.close(WebSocketCoreSession.java:239)
	at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.processHandlerError(WebSocketCoreSession.java:370)
	at org.eclipse.jetty.websocket.core.internal.WebSocketConnection.onIdleExpired(WebSocketConnection.java:233)
	at org.eclipse.jetty.http2.server.ServerHTTP2StreamEndPoint.onTimeout(ServerHTTP2StreamEndPoint.java:60)
	at org.eclipse.jetty.http2.server.HTTP2ServerConnection.onStreamTimeout(HTTP2ServerConnection.java:180)
	at org.eclipse.jetty.http2.server.HTTP2ServerConnectionFactory$HTTPServerSessionListener.onIdleTimeout(HTTP2ServerConnectionFactory.java:183)
	at org.eclipse.jetty.http2.HTTP2Stream.notifyIdleTimeout(HTTP2Stream.java:863)
	at org.eclipse.jetty.http2.HTTP2Stream.onIdleExpired(HTTP2Stream.java:326)
	at org.eclipse.jetty.http2.HTTP2Session$StreamTimeouts.onExpired(HTTP2Session.java:2357)
	at org.eclipse.jetty.http2.HTTP2Session$StreamTimeouts.onExpired(HTTP2Session.java:2341)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:105)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:191)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:293)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)

With HTTP/1.1, the websocket is closed gracefully because there is no HTTP2Session to expire first. So when the websocket itself expires, the websocket session is still open and a close frame can be sent.

I'm not sure what the correct low-level behavior would be. Maybe the websocket should expire first, and only then the HTTP2 session. Or maybe when the HTTP2 session expires, this should immediatly be handled gracefully by already sending a close frame.

How to reproduce?

1. Start a Jetty server that exposes a websocket over HTTP/2.
2. Connect to the websocket from a client.
3. Wait for the idle timeout.

When the timeout happens, the client should see a close frame with status 1001, but it doesn't.

Probably related to #7740 and #5447.

[joakime]

Interesting analysis.
@lachlan-roberts @sbordet what you think?

[sbordet]

I think there we should handle this properly as if it was a websocket timeout.