Bug 66281 - NIO2 breaks HTTP2 responses after 5 seconds
Summary: NIO2 breaks HTTP2 responses after 5 seconds
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 10
Classification: Unclassified
Component: Connectors (show other bugs)
Version: 10.1.0
Hardware: All All
: P2 major (vote)
Target Milestone: ------
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2022-09-28 12:51 UTC by Rainer Jung
Modified: 2022-09-30 19:34 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Rainer Jung 2022-09-28 12:51:41 UTC
NIO2 connector with HTTP2 and JSSE.

Client is (recent) curl or recent Firefox or Chrome.

If I call a JSP, that sleeps for eg. 8 seconds before responding, then the client gets after 5 seconds:

curl: (92) HTTP/2 stream 1 was not closed cleanly before end of the underlying stream

Browser communication ends as well before the response is generated and received.

The example JSP is:


Begin Sleeping ...
<%
Thread.sleep(8000);
%>
Done

Turning on debug logging I see:

28-Sep-2022 11:11:11.408 FINE [https-jsse-nio2-8444-exec-5] org.apache.coyote.http2.Http2AsyncParser$FrameCompletionHandler.failed Connection [0], Stream [0], Frame type [null], Error
        java.net.SocketTimeoutException
                at org.apache.tomcat.util.net.SocketWrapperBase$VectoredIOCompletionHandler.failed(SocketWrapperBase.java:1124)
                at org.apache.tomcat.util.net.SocketWrapperBase$VectoredIOCompletionHandler.failed(SocketWrapperBase.java:1066)
                at org.apache.tomcat.util.net.SecureNio2Channel$2.failed(SecureNio2Channel.java:1158)
                at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:129)
                at java.base/sun.nio.ch.Invoker$2.run(Invoker.java:219)
                at java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
                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(Thread.java:829)


The request actually finished in Tomvcat, but when it tries to start back the response it gets another exception because of the closed stream


28-Sep-2022 11:11:14.809 FINE [https-jsse-nio2-8444-exec-4] org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW] reported while processing request
        org.apache.coyote.CloseNowException: Connection [0], Stream [1], This stream is not writable
                at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:269)
                at org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:939)
...


This only happens for NIO2, not NIO.

It happens for 10.1.0, 10.0.26, 9.0.67 but also for the older e.g. 10.0.10, 10.0.0 and 9.0.60.

Connector config I use:

    <Connector port="8444" protocol="org.apache.coyote.http11.Http11Nio2Protocol"
               maxThreads="150" SSLEnabled="true">
        <UpgradeProtocol className="org.apache.coyote.http2.Http2Protocol" />
        <SSLHostConfig certificateVerification="false">
            <Certificate certificateKeystoreFile="${catalina.base}/conf/keystore/keystore.jks"
                         certificateKeystorePassword="mypass" />
        </SSLHostConfig>
    </Connector>

and for comparison with the working NIO(1):

    <Connector port="8443" protocol="org.apache.coyote.http11.Http11NioProtocol"
               maxThreads="150" SSLEnabled="true">
        <UpgradeProtocol className="org.apache.coyote.http2.Http2Protocol" />
        <SSLHostConfig certificateVerification="false">
            <Certificate certificateKeystoreFile="${catalina.base}/conf/keystore/keystore.jks"
                         certificateKeystorePassword="mypass" />
        </SSLHostConfig>
    </Connector>

Regards,

Rainer
Comment 1 Mark Thomas 2022-09-30 19:34:11 UTC
Fixed in:
- 10.1.x for 10.1.1 onwards
- 10.0.x for 10.0.27 onwards
-  9.0.x for  9.0.68 onwards
-  8.5.x for  8.5.83 onwards