You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by Rainer Jung <ra...@kippdata.de> on 2022/09/28 09:40:39 UTC
HTTP2 with NIO2 broken?
Hi all,
I observe the following behavior:
NIO2 connector with HTTP2 and JSSE.
Client is (recent) curl or recent Firefox or Chrome.
If I call a JSP, that sleep for 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
The 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.20 and 9.0.60.
Should I open an issue?
Best regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: HTTP2 with NIO2 broken?
Posted by Rainer Jung <ra...@kippdata.de>.
https://bz.apache.org/bugzilla/show_bug.cgi?id=66281
Thanks,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: HTTP2 with NIO2 broken?
Posted by Mark Thomas <ma...@apache.org>.
On 28/09/2022 11:03, Rainer Jung wrote:
> Am 28.09.2022 um 11:40 schrieb Rainer Jung:
>> Hi all,
>>
>> I observe the following behavior:
>>
>> NIO2 connector with HTTP2 and JSSE.
>> Client is (recent) curl or recent Firefox or Chrome.
>>
>> If I call a JSP, that sleep for 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
>>
>> The 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.20 and 9.0.60.
>>
>> Should I open an issue?
>
> Also happens with 10.0.10 and 10.0.0, so an old bug.
I don't think we'll forget about this problem but please open a BZ issue
so we can track / reference it easily.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: HTTP2 with NIO2 broken?
Posted by Rainer Jung <ra...@kippdata.de>.
Am 28.09.2022 um 11:40 schrieb Rainer Jung:
> Hi all,
>
> I observe the following behavior:
>
> NIO2 connector with HTTP2 and JSSE.
> Client is (recent) curl or recent Firefox or Chrome.
>
> If I call a JSP, that sleep for 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
>
> The 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.20 and 9.0.60.
>
> Should I open an issue?
Also happens with 10.0.10 and 10.0.0, so an old bug.
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
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org