You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Mark Thomas <ma...@apache.org> on 2022/07/04 17:37:29 UTC
Re: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
On 30/06/2022 07:40, Mark Thomas wrote:
<snip/>
> I think I'm going to need the sample app to investigate this.
I have received the sample application and can recreate the issue.
Going back to your original summary:
<quote>
1) Main page was requested by Firefox from Tomcat (GET ...)
2) Tomcat sends the first compressed chunks of data to the browser
3) Firefox reads the first packages and notices, that additional
resources are needed (CSS, JS ...)
4) While Tomcat is still sending the main page in chunks, the browser is
already requesting additional resources on other channels
5) Firefox is sending a RST_STREAM and closes that last requested
stream(s) (dunno why it does request first and then closes the channel)
6) Tomcat is sending a GoAway message to the browser
7) Tomcat stops also sending the main page (on a different channel)
</quote>
I tested with 10.0.x.
I don't see the above sequence.
I ran the test 4 times, closing the browser between each test
When things go wrong it appears that FireFox is re-using the main page
(ticket.jsp) from a cache.
I see the additional resources being requested and then cancelled.
I do not see any GOAWAY messages from Tomcat.
I do see a single GOAWAY message from the browser to Tomcat when I close
the browser window (as expected).
I don't see anything going wrong on the Tomcat side.
At the moment, this looks to me like an issue with Firefox rather than
with Tomcat.
If you can narrow the test case to something that shows Tomcat doing
something wrong, then I'd be happy to look at this again.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: Tomcat 10 with Http2 and compression sometimes causes pages to load partly in FF
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
> -----Ursprüngliche Nachricht-----
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Montag, 7. November 2022 12:43
> An: users@tomcat.apache.org
> Betreff: Re: Tomcat 10 with Http2 and compression sometimes causes pages to
> load partly in FF
>
> On 06/11/2022 19:35, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> > Hello Mark,
> >
> > I found some time for digging into this older topic with the combination http2,
> Firefox, Compression and only partly loaded pages.
> > I hope I or the topic doesn’t bother you.
>
> Not at all. If there is a Tomcat bug here, I want to get it fixed.
>
> > As apache-tomcat-10.0.0-M7 doesn’t show the problem with broken pages
> > in FF (jsp page only partly loads) and it showed up with apache-tomcat-10.0.0-
> M8, I was taking a look at the changes. This was my current approach to this
> topic.
> >
> > The change which makes the difference is in Http2UpgradeHandler:
> > int reserveWindowSize(Stream stream, int reservation, boolean block)
> > throws IOException { ...
> > if (!stream.canWrite()) {
> >
> stream.doStreamCancel(sm.getString("upgradeHandler.stream.notWritable",
> > stream.getConnectionId(), stream.getIdAsString()),
> Http2Error.STREAM_CLOSED);
> > }
> >
> > The older version just threw an exception instead of calling doStreamCancel
> when the client is closing the stream:
> >
> > if (!stream.canWrite()) {
> > throw new CloseNowException(
> > sm.getString("upgradeHandler.stream.notWritable",
> > stream.getConnectionId(), stream.getIdentifier()));
> > }
> >
> > The method doStreamCancel is setting some properties before throwing also
> a CloseNowException:
> >
> > void doStreamCancel(String msg, Http2Error error) throws
> CloseNowException {
> > StreamException se = new StreamException(msg, error, getIdAsInt());
> > // Prevent the application making further writes
> > streamOutputBuffer.closed = true;
> > // Prevent Tomcat's error handling trying to write
> > coyoteResponse.setError();
> > coyoteResponse.setErrorReported();
> > // Trigger a reset once control returns to Tomcat
> > streamOutputBuffer.reset = se;
> > throw new CloseNowException(msg, se);
> > }
> >
> > The line "streamOutputBuffer.closed = true;" seems to be responsible for the
> partly shown pages in FF.
> > If I comment out this line, no problem shows up with FF, http2 and
> compression="force".
>
> Nice bit of detective work. Setting streamOutputBuffer.closed=true will prevent
> the application from writing the rest of the resource content which would
> explain the partial response seen on the client side.
>
> > This line seems to have some side effect somewhere else.
> > Unfortunately, I don’t know the code of Tomcat and http2 protocol.
> > Can you think about which side effect this line might have (in combination
> with compression / GZipOutputFilter)?
> > Maybe you have an inspiring idea about the cause or have a hint, where to
> follow the track.
>
> I think this is more symptom rather than root cause. The symptom is visible
> because of the change to call doStreamCancel() but the question for me is what
> is triggering this to be called in the first place.
>
> Digging into that a little:
>
> stream.canWrite() needs to return false.
>
> That happens when the Stream is in one of the states that does not permit
> write. Those states are:
> IDLE
> RESERVED_LOCAL
> HALF_CLOSED_LOCAL
> CLOSED_RX
> CLOSED_TX
> CLOSED_RST_RX
> CLOSED_RST_TX
>
> One thing we could do is improve the error message so it logs the current
> Stream state. That will help narrow down how the Stream got into that state.
>
> I'll get than done for the next set of releases.
>
> Mark
Thank you so much for investigating this.
As far as I saw in the Wireshark dump, the Firefox-Browser is closing one http2 stream (don’t know why FF behaves like that).
It seems FF is fetching cached resources and after fetching recognizes that it doesn’t need it.
So the reason is that the browser is cancelling / closing the http2-stream.
The closed stream happens in version 10.0.0-M7 and 10.0.0-M8 but only causes issues in version M8. Thus I assume that the issue is somewhere later on in the handling.
Strangely it causes only problems in connection with the compression=on/force setting.
Re: Tomcat 10 with Http2 and compression sometimes causes pages to load partly in FF
Posted by Mark Thomas <ma...@apache.org>.
On 06/11/2022 19:35, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello Mark,
>
> I found some time for digging into this older topic with the combination http2, Firefox, Compression and only partly loaded pages.
> I hope I or the topic doesn’t bother you.
Not at all. If there is a Tomcat bug here, I want to get it fixed.
> As apache-tomcat-10.0.0-M7 doesn’t show the problem with broken pages in FF (jsp page only partly loads) and
> it showed up with apache-tomcat-10.0.0-M8, I was taking a look at the changes. This was my current approach to this topic.
>
> The change which makes the difference is in Http2UpgradeHandler:
> int reserveWindowSize(Stream stream, int reservation, boolean block) throws IOException {
> ...
> if (!stream.canWrite()) {
> stream.doStreamCancel(sm.getString("upgradeHandler.stream.notWritable",
> stream.getConnectionId(), stream.getIdAsString()), Http2Error.STREAM_CLOSED);
> }
>
> The older version just threw an exception instead of calling doStreamCancel when the client is closing the stream:
>
> if (!stream.canWrite()) {
> throw new CloseNowException(
> sm.getString("upgradeHandler.stream.notWritable",
> stream.getConnectionId(), stream.getIdentifier()));
> }
>
> The method doStreamCancel is setting some properties before throwing also a CloseNowException:
>
> void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
> StreamException se = new StreamException(msg, error, getIdAsInt());
> // Prevent the application making further writes
> streamOutputBuffer.closed = true;
> // Prevent Tomcat's error handling trying to write
> coyoteResponse.setError();
> coyoteResponse.setErrorReported();
> // Trigger a reset once control returns to Tomcat
> streamOutputBuffer.reset = se;
> throw new CloseNowException(msg, se);
> }
>
> The line "streamOutputBuffer.closed = true;" seems to be responsible for the partly shown pages in FF.
> If I comment out this line, no problem shows up with FF, http2 and compression="force".
Nice bit of detective work. Setting streamOutputBuffer.closed=true will
prevent the application from writing the rest of the resource content
which would explain the partial response seen on the client side.
> This line seems to have some side effect somewhere else.
> Unfortunately, I don’t know the code of Tomcat and http2 protocol.
> Can you think about which side effect this line might have (in combination with compression / GZipOutputFilter)?
> Maybe you have an inspiring idea about the cause or have a hint, where to follow the track.
I think this is more symptom rather than root cause. The symptom is
visible because of the change to call doStreamCancel() but the question
for me is what is triggering this to be called in the first place.
Digging into that a little:
stream.canWrite() needs to return false.
That happens when the Stream is in one of the states that does not
permit write. Those states are:
IDLE
RESERVED_LOCAL
HALF_CLOSED_LOCAL
CLOSED_RX
CLOSED_TX
CLOSED_RST_RX
CLOSED_RST_TX
One thing we could do is improve the error message so it logs the
current Stream state. That will help narrow down how the Stream got into
that state.
I'll get than done for the next set of releases.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Tomcat 10 with Http2 and compression sometimes causes pages to load partly in FF
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
I found some time for digging into this older topic with the combination http2, Firefox, Compression and only partly loaded pages.
I hope I or the topic doesn’t bother you.
As apache-tomcat-10.0.0-M7 doesn’t show the problem with broken pages in FF (jsp page only partly loads) and
it showed up with apache-tomcat-10.0.0-M8, I was taking a look at the changes. This was my current approach to this topic.
The change which makes the difference is in Http2UpgradeHandler:
int reserveWindowSize(Stream stream, int reservation, boolean block) throws IOException {
...
if (!stream.canWrite()) {
stream.doStreamCancel(sm.getString("upgradeHandler.stream.notWritable",
stream.getConnectionId(), stream.getIdAsString()), Http2Error.STREAM_CLOSED);
}
The older version just threw an exception instead of calling doStreamCancel when the client is closing the stream:
if (!stream.canWrite()) {
throw new CloseNowException(
sm.getString("upgradeHandler.stream.notWritable",
stream.getConnectionId(), stream.getIdentifier()));
}
The method doStreamCancel is setting some properties before throwing also a CloseNowException:
void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
StreamException se = new StreamException(msg, error, getIdAsInt());
// Prevent the application making further writes
streamOutputBuffer.closed = true;
// Prevent Tomcat's error handling trying to write
coyoteResponse.setError();
coyoteResponse.setErrorReported();
// Trigger a reset once control returns to Tomcat
streamOutputBuffer.reset = se;
throw new CloseNowException(msg, se);
}
The line "streamOutputBuffer.closed = true;" seems to be responsible for the partly shown pages in FF.
If I comment out this line, no problem shows up with FF, http2 and compression="force".
This line seems to have some side effect somewhere else.
Unfortunately, I don’t know the code of Tomcat and http2 protocol.
Can you think about which side effect this line might have (in combination with compression / GZipOutputFilter)?
Maybe you have an inspiring idea about the cause or have a hint, where to follow the track.
Thank you very much in advance,
Thomas
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: AW: AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by Mark Thomas <ma...@apache.org>.
On 21/09/2022 06:48, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hallo Mark,
>
> thank you for the explanation.
> Could you guide me in this case?
> Shall I set all logging options in tomcat to trace (logging.properties)?
Thomas,
The level of logging in your most recent off-list trace was perfect. The
issue was that the logging did not show the problem you described.
The issue you described is that the client resets a single stream and
Tomcat then incorrectly closes the entire connection. That in turns
triggers stack traces in the logs as the application attempts to write
to the other streams in the connection as those streams are now closed.
I could not find any evidence of that in the logging you provided. Every
stack trace associated with a write to a closed stream was preceded by
the client sending a reset frame for that stream.
You need to:
- recreate the case of Tomcat closing an entire connection in response
to the client resetting a single stream
- capture HTTP/2 debug logs when this occurs
- provide those logs
Mark
>
> Thanks! Thomas
>
>> -----Ursprüngliche Nachricht-----
>> Von: Mark Thomas <ma...@apache.org>
>> Gesendet: Dienstag, 20. September 2022 22:28
>> An: users@tomcat.apache.org
>> Betreff: Re: AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
>> sometimes closes connection with Firefox
>>
>> On 20/09/2022 20:22, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>>> Hello Mark,
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Mark Thomas <ma...@apache.org>
>>>> Gesendet: Dienstag, 20. September 2022 20:13
>>>> An: users@tomcat.apache.org
>>>> Betreff: Re: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
>>>> sometimes closes connection with Firefox
>>>>
>>>> On 20/09/2022 17:58, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>>>>> Hello Mark,
>>>>>
>>>>>
>>>>> I will send you the log and access-log to your email address.
>>>>>
>>>>> I am not sure whether it contradicts the observation.
>>>>>
>>>>>
>>>>> For example:
>>>>>
>>>>> - Browser opens a TCP-connection and requests the HTML page.
>>>>>
>>>>> - Tomcat sends single packages with HTML via http2-stream no 1.
>>>>>
>>>>> - Browser requests CSS via http2-stream no 2.
>>>>>
>>>>> - Tomcat serves HTML via stream 1 and css via stream 2.
>>>>>
>>>>> - Browser closes stream 2 which triggers tomcat to close the whole
>>>>> TCP
>>>> connection including stream 1.
>>>>>
>>>>> - Thus the html stream is also cancelled, leading to a partly
>>>>> visible html
>>>> page.
>>>>
>>>> Thomas,
>>>>
>>>> I can find no evidence of the sequence above in the logs you provided.
>>>> In all the cases I could find, the client first reset the stream
>>>> sending
>>>> 0x08 (cancel) as the reason.
>>>>
>>>> If you can provide a connection and stream id that exhibits the
>>>> behaviour you are describing, I'll be happy to look at it.
>>>>
>>>> Mark
>>>
>>> I can record a network trace with wireshark if this helps.
>>> The last time I saw that the browser aborts one stream as you described.
>>> It shouldn’t close the whole TCP connection, just the stream.
>>> I try to get a wireshark dump on weekend.
>>
>> Thomas,
>>
>> A wireshark trace is unlikely to help. I need the Tomcat debug logs to see
>> what is happening internally.
>>
>> You need to provide the debug log trace for an instance where Tomcat
>> closes the entire connection after the client resets a single stream.
>>
>> In all the examples in the previous log, every time there was a stack trace for
>> a stream, it was preceeded by the client resetting that stream
>> - and hence was normal behaviour.
>>
>> Mark
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hallo Mark,
thank you for the explanation.
Could you guide me in this case?
Shall I set all logging options in tomcat to trace (logging.properties)?
Thanks! Thomas
> -----Ursprüngliche Nachricht-----
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Dienstag, 20. September 2022 22:28
> An: users@tomcat.apache.org
> Betreff: Re: AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
> sometimes closes connection with Firefox
>
> On 20/09/2022 20:22, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> > Hello Mark,
> >
> >> -----Ursprüngliche Nachricht-----
> >> Von: Mark Thomas <ma...@apache.org>
> >> Gesendet: Dienstag, 20. September 2022 20:13
> >> An: users@tomcat.apache.org
> >> Betreff: Re: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
> >> sometimes closes connection with Firefox
> >>
> >> On 20/09/2022 17:58, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> >>> Hello Mark,
> >>>
> >>>
> >>> I will send you the log and access-log to your email address.
> >>>
> >>> I am not sure whether it contradicts the observation.
> >>>
> >>>
> >>> For example:
> >>>
> >>> - Browser opens a TCP-connection and requests the HTML page.
> >>>
> >>> - Tomcat sends single packages with HTML via http2-stream no 1.
> >>>
> >>> - Browser requests CSS via http2-stream no 2.
> >>>
> >>> - Tomcat serves HTML via stream 1 and css via stream 2.
> >>>
> >>> - Browser closes stream 2 which triggers tomcat to close the whole
> >>> TCP
> >> connection including stream 1.
> >>>
> >>> - Thus the html stream is also cancelled, leading to a partly
> >>> visible html
> >> page.
> >>
> >> Thomas,
> >>
> >> I can find no evidence of the sequence above in the logs you provided.
> >> In all the cases I could find, the client first reset the stream
> >> sending
> >> 0x08 (cancel) as the reason.
> >>
> >> If you can provide a connection and stream id that exhibits the
> >> behaviour you are describing, I'll be happy to look at it.
> >>
> >> Mark
> >
> > I can record a network trace with wireshark if this helps.
> > The last time I saw that the browser aborts one stream as you described.
> > It shouldn’t close the whole TCP connection, just the stream.
> > I try to get a wireshark dump on weekend.
>
> Thomas,
>
> A wireshark trace is unlikely to help. I need the Tomcat debug logs to see
> what is happening internally.
>
> You need to provide the debug log trace for an instance where Tomcat
> closes the entire connection after the client resets a single stream.
>
> In all the examples in the previous log, every time there was a stack trace for
> a stream, it was preceeded by the client resetting that stream
> - and hence was normal behaviour.
>
> Mark
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
Re: AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by Mark Thomas <ma...@apache.org>.
On 20/09/2022 20:22, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello Mark,
>
>> -----Ursprüngliche Nachricht-----
>> Von: Mark Thomas <ma...@apache.org>
>> Gesendet: Dienstag, 20. September 2022 20:13
>> An: users@tomcat.apache.org
>> Betreff: Re: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
>> sometimes closes connection with Firefox
>>
>> On 20/09/2022 17:58, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>>> Hello Mark,
>>>
>>>
>>> I will send you the log and access-log to your email address.
>>>
>>> I am not sure whether it contradicts the observation.
>>>
>>>
>>> For example:
>>>
>>> - Browser opens a TCP-connection and requests the HTML page.
>>>
>>> - Tomcat sends single packages with HTML via http2-stream no 1.
>>>
>>> - Browser requests CSS via http2-stream no 2.
>>>
>>> - Tomcat serves HTML via stream 1 and css via stream 2.
>>>
>>> - Browser closes stream 2 which triggers tomcat to close the whole TCP
>> connection including stream 1.
>>>
>>> - Thus the html stream is also cancelled, leading to a partly visible html
>> page.
>>
>> Thomas,
>>
>> I can find no evidence of the sequence above in the logs you provided.
>> In all the cases I could find, the client first reset the stream sending
>> 0x08 (cancel) as the reason.
>>
>> If you can provide a connection and stream id that exhibits the behaviour you
>> are describing, I'll be happy to look at it.
>>
>> Mark
>
> I can record a network trace with wireshark if this helps.
> The last time I saw that the browser aborts one stream as you described.
> It shouldn’t close the whole TCP connection, just the stream.
> I try to get a wireshark dump on weekend.
Thomas,
A wireshark trace is unlikely to help. I need the Tomcat debug logs to
see what is happening internally.
You need to provide the debug log trace for an instance where Tomcat
closes the entire connection after the client resets a single stream.
In all the examples in the previous log, every time there was a stack
trace for a stream, it was preceeded by the client resetting that stream
- and hence was normal behaviour.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
> -----Ursprüngliche Nachricht-----
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Dienstag, 20. September 2022 20:13
> An: users@tomcat.apache.org
> Betreff: Re: AW: AW: AW: AW: Tomcat 10 with Http2 and compression
> sometimes closes connection with Firefox
>
> On 20/09/2022 17:58, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> > Hello Mark,
> >
> >
> > I will send you the log and access-log to your email address.
> >
> > I am not sure whether it contradicts the observation.
> >
> >
> > For example:
> >
> > - Browser opens a TCP-connection and requests the HTML page.
> >
> > - Tomcat sends single packages with HTML via http2-stream no 1.
> >
> > - Browser requests CSS via http2-stream no 2.
> >
> > - Tomcat serves HTML via stream 1 and css via stream 2.
> >
> > - Browser closes stream 2 which triggers tomcat to close the whole TCP
> connection including stream 1.
> >
> > - Thus the html stream is also cancelled, leading to a partly visible html
> page.
>
> Thomas,
>
> I can find no evidence of the sequence above in the logs you provided.
> In all the cases I could find, the client first reset the stream sending
> 0x08 (cancel) as the reason.
>
> If you can provide a connection and stream id that exhibits the behaviour you
> are describing, I'll be happy to look at it.
>
> Mark
I can record a network trace with wireshark if this helps.
The last time I saw that the browser aborts one stream as you described.
It shouldn’t close the whole TCP connection, just the stream.
I try to get a wireshark dump on weekend.
> >
> > I hope the logs will provide more information.
> >
> >
> > Thanks! Thomas
> >
> >
> > ________________________________
> > Von: Mark Thomas <ma...@apache.org>
> > Gesendet: Dienstag, 20. September 2022 09:04
> > An: users@tomcat.apache.org
> > Betreff: Re: AW: AW: AW: Tomcat 10 with Http2 and compression
> > sometimes closes connection with Firefox
> >
> > On 19/09/2022 19:19, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> >> Hello Mark,
> >>
> >> thanks for the update.
> >>
> >> The commit looked promising. I tried with Tomcat 10.1 M17 but
> unfortunately it didn't help.
> >>
> >> The partly loaded website is still occuring.
> >>
> >>
> >> Setting http2 logging to fine, I can see the following stack:
> >
> > That looks like the client reset the stream but that doesn't match
> > what you are observing which sounds like Tomcat is truncating the
> response.
> >
> >> 19-Sep-2022 20:07:16.651 FEIN [https-openssl-nio-443-exec-9]
> >> org.apache.coyote.AbstractProcessor.setErrorState Error state
> >> [CLOSE_NOW] reported while processing request
> >> org.apache.coyote.CloseNowException: Connection [1], Stream [23],
> >> This stream is not writable
> >
> > That this is happening with connection 1 is good. It means it should
> > be easy to reproduce. Please can you:
> > - enable debug logging for HTTP/2
> > - restart Tomcat
> > - trigger this problem
> > - provide the full debug logs
> >
> > I want to trace what is happening on the HTTP/2 connection leading up
> > to the truncation occurring.
> >
> > Thanks,
> >
> > Mark
> >
> >
> >> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:258)
> >> at
> >>
> org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2U
> p
> >> gradeHandler.java:919) at
> >>
> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:9
> >> 45) at
> >>
> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:8
> >> 91) at
> >>
> org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:990
> >> ) at
> >> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilte
> >> r.java:128) at
> >> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:
> >> 71) at
> >>
> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcesso
> >> r.java:230) at
> >> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:391
> >> ) at org.apache.coyote.Response.action(Response.java:210)
> >> at
> >> org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:25
> >> 8) at
> >> org.apache.catalina.connector.Response.finishResponse(Response.java:4
> >> 18) at
> >> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.jav
> >> a:388) at
> >> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:
> >> 426) at
> >> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLig
> >> ht.java:65) at
> >>
> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:
> >> 87) at
> >> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> >> at
> >>
> org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoo
> >> lExecutor.java:1191) at
> >>
> org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPo
> >> olExecutor.java:659) at
> >>
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskTh
> >> read.java:61) at java.base/java.lang.Thread.run(Thread.java:833)
> >> Caused by: org.apache.coyote.http2.StreamException: Connection [1],
> >> Stream [23], This stream is not writable at
> >> org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:250)
> >> ... 20 more
> >>
> >>
> >>
> >> Looks like the Exception bubbles up from the last line of tthis method:
> >>
> >> void doStreamCancel(String msg, Http2Error error) throws
> CloseNowException {
> >> StreamException se = new StreamException(msg, error,
> getIdAsInt());
> >> // Prevent the application making further writes
> >> streamOutputBuffer.closed = true;
> >> // Prevent Tomcat's error handling trying to write
> >> coyoteResponse.setError();
> >> coyoteResponse.setErrorReported();
> >> // Trigger a reset once control returns to Tomcat
> >> streamOutputBuffer.reset = se;
> >> throw new CloseNowException(msg, se);
> >> }
> >>
> >> The CloseNowException() bubbles up without being caught maybe (?)
> >> Stream.write(...) is not contained here.
> >>
> >> Greetings, Thoas
> >>
> >> ________________________________
> >> Von: Mark Thomas <ma...@apache.org>
> >> Gesendet: Montag, 19. September 2022 19:22
> >> An: users@tomcat.apache.org
> >> Betreff: Re: AW: AW: Tomcat 10 with Http2 and compression sometimes
> >> closes connection with Firefox
> >>
> >> Thomas,
> >>
> >> Please update to the latest 10.1.x release and re-test. There is what
> >> looks like a fix for this issue in 10.1.0-M12:
> >>
> >>
> https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95
> c98
> >> 2827e9753dd
> >>
> >> Mark
> >>
> >>
> >> On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> >>> Hello,
> >>>
> >>> I would create a ticket and sum up all the collected information about
> this issue, if there are no further suggestions.
> >>>
> >>> Closing a single stream in http2 causes an internal exception in
> StreamProcessor which bubbles up in different ways, depending whether
> http-compression is active or not.
> >>> In the first case it leads to closing the complete TCP connection.
> >>>
> >>> Thanks! Thomas
> >>>
> >>>
> >>>> -----Ursprüngliche Nachricht-----
> >>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
> >>>> <Th...@speed4trade.com.INVALID>
> >>>> Gesendet: Donnerstag, 28. Juli 2022 22:25
> >>>> An: Tomcat Users List <us...@tomcat.apache.org>
> >>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> >>>> closes connection with Firefox
> >>>>
> >>>> Hello Mark,
> >>>>
> >>>> I got a stack trace which also shows the involvement of the gzip
> >>>> filter. I set the loglevel for the http2-StreamProcessor to get the
> details.
> >>>> The stack trace was written when the problem with FF occurred.
> >>>> FF closed one single stream in http2 connection and tomcat seemed
> >>>> to have closed the whole TCP connection:
> >>>>
> >>>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
> >>>> org.apache.coyote.http2.StreamProcessor.process Connection [0],
> >>>> Stream [23], An error occurred during processing that was fatal to the
> connection
> >>>> java.lang.IllegalStateException: Connection [0],
> >>>> Stream [23], Unable to write to stream once it has been closed
> >>>> at
> >>>>
> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
> >>>> 880)
> >>>> at
> >>>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.
> >>>> write(
> >>>> GzipOutputFilter.java:158)
> >>>> at
> >>>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.ja
> >>>> va:171
> >>>> )
> >>>> at
> >>>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFil
> >>>> ter.java
> >>>> :125)
> >>>> at
> >>>>
> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.jav
> >>>> a:71
> >>>> )
> >>>> at
> >>>>
> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
> >>>> java:209)
> >>>> at
> >>>>
> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
> >>>> at
> >>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.jav
> >>>> a:420
> >>>> )
> >>>> at
> >>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorL
> >>>> ight.ja
> >>>> va:65)
> >>>> at
> >>>>
> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.jav
> >>>> a:73
> >>>> )
> >>>> at
> >>>>
> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> >>>> at
> >>>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadP
> >>>> oolE
> >>>> xecutor.java:1136)
> >>>> at
> >>>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Thread
> >>>> Pool
> >>>> Executor.java:635)
> >>>> at
> >>>>
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(Task
> >>>> Thr
> >>>> ead.java:61)
> >>>> at
> >>>> java.base/java.lang.Thread.run(Thread.java:833)
> >>>>
> >>>> I hope the stack shows the problem and helps to identify the problem.
> >>>> Seems like the error handling has changed a bit with Tomcat 10.0.0
> >>>> M8 with
> >>>> http2 and is causing the issue.
> >>>>
> >>>> Thanks in advance!
> >>>> Thomas
> >>>>
> >>>>> -----Ursprüngliche Nachricht-----
> >>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
> >>>>> <Th...@speed4trade.com.INVALID>
> >>>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
> >>>>> An: Tomcat Users List <us...@tomcat.apache.org>
> >>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> >>>>> closes connection with Firefox
> >>>>>
> >>>>> Oh... I also discovered an additional message in the wireshark dump.
> >>>>> Tomcat replied with a goaway packet with the text:
> >>>>> Connection [22], Stream [19], An error occurred during
> >>>>> processing that was fatal to the connection
> >>>>>
> >>>>>> -----Ursprüngliche Nachricht-----
> >>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
> >>>>>> <Th...@speed4trade.com.INVALID>
> >>>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
> >>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
> >>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> >>>>>> closes connection with Firefox
> >>>>>>
> >>>>>> Hello Mark,
> >>>>>>
> >>>>>> I did some further investigations. I hope I don’t bother you with
> >>>>>> this
> >>>> topic.
> >>>>>>
> >>>>>> I was trying to narrow down the tomcat version where the problem
> >>>>>> started to appear.
> >>>>>> The problem with the interrupted connection started with
> >>>>>> 10.0.0-M8 With Tomcat 10.0.0-M7 everything works fine.
> >>>>>>
> >>>>>> Comparing the sources, there are some (maybe relevant) changes in
> >>>>>> the
> >>>>>> org.apache.coyote.http2 package from M7 --> M8:
> >>>>>> - Http2AsynUpgradeHandler
> >>>>>> - Http2UpgradeHandler
> >>>>>> - Stream
> >>>>>> - StreamProcessor
> >>>>>>
> >>>>>> The observed problem was, that the browser (firefox) was sending
> >>>>>> a RST_Stream packet to close a single stream within the http2
> >>>>>> protocol and tomcat was closing the whole connection instead of
> >>>>>> closing just that stream (wireshark dump would be available).
> >>>>>>
> >>>>>> In Stream.java a new method "doStreamCancel" was introduced (or
> >>>>>> an old method was renamed) with release M8.
> >>>>>> This looks related to the observed problem mentioned above.
> >>>>>>
> >>>>>> Does this information help to take a look again at this problem?
> >>>>>> If I should try something or can assist with testing, just let me know.
> >>>>>>
> >>>>>> Thanks!
> >>>>>> Thomas
> >>>>>>
> >>>>>>
> >>>>>>
> >>>>>>
> >>>>>>> -----Ursprüngliche Nachricht-----
> >>>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
> >>>>>>> <Th...@speed4trade.com.INVALID>
> >>>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
> >>>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
> >>>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression
> sometimes
> >>>>>>> closes connection with Firefox
> >>>>>>>
> >>>>>>> Hallo Mark,
> >>>>>>>
> >>>>>>>> -----Ursprüngliche Nachricht-----
> >>>>>>>> Von: Mark Thomas <ma...@apache.org>
> >>>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
> >>>>>>>> An: users@tomcat.apache.org
> >>>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression
> sometimes
> >>>>>>>> closes connection with Firefox
> >>>>>>>>
> >>>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
> >>>>>>>>
> >>>>>>>> <snip/>
> >>>>>>>>
> >>>>>>>>> I think I'm going to need the sample app to investigate this.
> >>>>>>>>
> >>>>>>>> I have received the sample application and can recreate the issue.
> >>>>>>>>
> >>>>>>>> Going back to your original summary:
> >>>>>>>>
> >>>>>>>> <quote>
> >>>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
> >>>>>>>> 2) Tomcat sends the first compressed chunks of data to the
> >>>>>>>> browser
> >>>>>>>> 3) Firefox reads the first packages and notices, that
> >>>>>>>> additional resources are needed (CSS, JS ...)
> >>>>>>>> 4) While Tomcat is still sending the main page in chunks, the
> >>>>>>>> browser is already requesting additional resources on other
> >>>>>>>> channels
> >>>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
> >>>>>>>> requested
> >>>>>>>> stream(s) (dunno why it does request first and then closes the
> >>>>>>>> channel)
> >>>>>>>> 6) Tomcat is sending a GoAway message to the browser
> >>>>>>>> 7) Tomcat stops also sending the main page (on a different
> >>>>>>>> channel) </quote>
> >>>>>>>>
> >>>>>>>> I tested with 10.0.x.
> >>>>>>>>
> >>>>>>>> I don't see the above sequence.
> >>>>>>>>
> >>>>>>>> I ran the test 4 times, closing the browser between each test
> >>>>>>>>
> >>>>>>>> When things go wrong it appears that FireFox is re-using the
> >>>>>>>> main page
> >>>>>>>> (ticket.jsp) from a cache.
> >>>>>>>>
> >>>>>>>> I see the additional resources being requested and then cancelled.
> >>>>>>>>
> >>>>>>>> I do not see any GOAWAY messages from Tomcat.
> >>>>>>>>
> >>>>>>>> I do see a single GOAWAY message from the browser to Tomcat
> >>>> when
> >>>>>>>> I close the browser window (as expected).
> >>>>>>>>
> >>>>>>>> I don't see anything going wrong on the Tomcat side.
> >>>>>>>>
> >>>>>>>> At the moment, this looks to me like an issue with Firefox
> >>>>>>>> rather than with Tomcat.
> >>>>>>>>
> >>>>>>>> If you can narrow the test case to something that shows Tomcat
> >>>>>>>> doing something wrong, then I'd be happy to look at this again.
> >>>>>>>>
> >>>>>>>> Mark
> >>>>>>>>
> >>>>>>>> ---------------------------------------------------------------
> >>>>>>>> -
> >>>>>>>> --
> >>>>>>>> --
> >>>>>>>> -
> >>>>>>>
> >>>>>>> Thank you very much for taking a look at it!
> >>>>>>>
> >>>>>>> I could also see that the browser cache is used sometimes.
> >>>>>>> Sometimes the jsp is requested from the server, sometimes not.
> >>>>>>>
> >>>>>>> I did several tests again and the behaviour is not very
> >>>>>>> consistent, thus it's hard to get a handle on the problem.
> >>>>>>> I was also thinking about the possibility of a Firefox bug but
> >>>>>>> this wouldn’t explain that:
> >>>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
> >>>>>>> Tomcat 9.x
> >>>>>>> 2) Users don’t report any problems with other internet websites
> >>>>>>> (using
> >>>>>>> Firefox)
> >>>>>>>
> >>>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
> >>>>>> always.
> >>>>>>> I recorded one session which matches my last description:
> >>>>>>> https://privfile.com/download.php?fid=62c3ec1170199-
> MTM2OTM=
> >>>>>>> I set up another PC for testing, thus the IP addresses
> >>>>>>> (source/target) differ and can be interpreted more easily.
> >>>>>>> Maybe the last Capture was not readable without the keyfile,
> >>>>>>> thus I exported it differently and it should be readable now.
> >>>>>>>
> >>>>>>> a) Is the behaviour according to the linked network trace an
> >>>>>>> expected behaviour? (sending a GoAway after a rst_stream
> >>>>>>> message)
> >>>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
> >>>>>>>
> >>>>>>> If you have any hints or suggestions, how I could narrow it
> >>>>>>> down, please drop a line.
> >>>>>>> I don’t have any big or great ideas at the moment.
> >>>>>>>
> >>>>>>> Thank you very much!
> >>>>>>> Thomas
> >>>>>>>
> >>>>
> >>>>
> >>>> -------------------------------------------------------------------
> >>>> -- To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> >>>> For additional commands, e-mail: users-help@tomcat.apache.org
> >>>
> >>>
> >>> --------------------------------------------------------------------
> >>> - To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> >>> For additional commands, e-mail: users-help@tomcat.apache.org
> >>>
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> >> For additional commands, e-mail: users-help@tomcat.apache.org
> >>
> >>
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> > For additional commands, e-mail: users-help@tomcat.apache.org
> >
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by Mark Thomas <ma...@apache.org>.
On 20/09/2022 17:58, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello Mark,
>
>
> I will send you the log and access-log to your email address.
>
> I am not sure whether it contradicts the observation.
>
>
> For example:
>
> - Browser opens a TCP-connection and requests the HTML page.
>
> - Tomcat sends single packages with HTML via http2-stream no 1.
>
> - Browser requests CSS via http2-stream no 2.
>
> - Tomcat serves HTML via stream 1 and css via stream 2.
>
> - Browser closes stream 2 which triggers tomcat to close the whole TCP connection including stream 1.
>
> - Thus the html stream is also cancelled, leading to a partly visible html page.
Thomas,
I can find no evidence of the sequence above in the logs you provided.
In all the cases I could find, the client first reset the stream sending
0x08 (cancel) as the reason.
If you can provide a connection and stream id that exhibits the
behaviour you are describing, I'll be happy to look at it.
Mark
>
>
> I hope the logs will provide more information.
>
>
> Thanks! Thomas
>
>
> ________________________________
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Dienstag, 20. September 2022 09:04
> An: users@tomcat.apache.org
> Betreff: Re: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
>
> On 19/09/2022 19:19, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>> Hello Mark,
>>
>> thanks for the update.
>>
>> The commit looked promising. I tried with Tomcat 10.1 M17 but unfortunately it didn't help.
>>
>> The partly loaded website is still occuring.
>>
>>
>> Setting http2 logging to fine, I can see the following stack:
>
> That looks like the client reset the stream but that doesn't match what
> you are observing which sounds like Tomcat is truncating the response.
>
>> 19-Sep-2022 20:07:16.651 FEIN [https-openssl-nio-443-exec-9] org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW] reported while processing request
>> org.apache.coyote.CloseNowException: Connection [1], Stream [23], This stream is not writable
>
> That this is happening with connection 1 is good. It means it should be
> easy to reproduce. Please can you:
> - enable debug logging for HTTP/2
> - restart Tomcat
> - trigger this problem
> - provide the full debug logs
>
> I want to trace what is happening on the HTTP/2 connection leading up to
> the truncation occurring.
>
> Thanks,
>
> Mark
>
>
>> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:258)
>> at org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:919)
>> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:945)
>> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:891)
>> at org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:990)
>> at org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java:128)
>> at org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71)
>> at org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:230)
>> at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:391)
>> at org.apache.coyote.Response.action(Response.java:210)
>> at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:258)
>> at org.apache.catalina.connector.Response.finishResponse(Response.java:418)
>> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:388)
>> at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
>> at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
>> at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:87)
>> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>> 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:833)
>> Caused by: org.apache.coyote.http2.StreamException: Connection [1], Stream [23], This stream is not writable
>> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:250)
>> ... 20 more
>>
>>
>>
>> Looks like the Exception bubbles up from the last line of tthis method:
>>
>> void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
>> StreamException se = new StreamException(msg, error, getIdAsInt());
>> // Prevent the application making further writes
>> streamOutputBuffer.closed = true;
>> // Prevent Tomcat's error handling trying to write
>> coyoteResponse.setError();
>> coyoteResponse.setErrorReported();
>> // Trigger a reset once control returns to Tomcat
>> streamOutputBuffer.reset = se;
>> throw new CloseNowException(msg, se);
>> }
>>
>> The CloseNowException() bubbles up without being caught maybe (?)
>> Stream.write(...) is not contained here.
>>
>> Greetings, Thoas
>>
>> ________________________________
>> Von: Mark Thomas <ma...@apache.org>
>> Gesendet: Montag, 19. September 2022 19:22
>> An: users@tomcat.apache.org
>> Betreff: Re: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
>>
>> Thomas,
>>
>> Please update to the latest 10.1.x release and re-test. There is what
>> looks like a fix for this issue in 10.1.0-M12:
>>
>> https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95c982827e9753dd
>>
>> Mark
>>
>>
>> On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>>> Hello,
>>>
>>> I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
>>>
>>> Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
>>> In the first case it leads to closing the complete TCP connection.
>>>
>>> Thanks! Thomas
>>>
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>> <Th...@speed4trade.com.INVALID>
>>>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>>> connection with Firefox
>>>>
>>>> Hello Mark,
>>>>
>>>> I got a stack trace which also shows the involvement of the gzip filter. I set
>>>> the loglevel for the http2-StreamProcessor to get the details.
>>>> The stack trace was written when the problem with FF occurred.
>>>> FF closed one single stream in http2 connection and tomcat seemed to have
>>>> closed the whole TCP connection:
>>>>
>>>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
>>>> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
>>>> [23], An error occurred during processing that was fatal to the connection
>>>> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
>>>> to write to stream once it has been closed
>>>> at
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
>>>> 880)
>>>> at
>>>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
>>>> GzipOutputFilter.java:158)
>>>> at
>>>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
>>>> )
>>>> at
>>>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
>>>> :125)
>>>> at
>>>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
>>>> )
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
>>>> java:209)
>>>> at
>>>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
>>>> )
>>>> at
>>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
>>>> va:65)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
>>>> )
>>>> at
>>>> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>>>> at
>>>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
>>>> xecutor.java:1136)
>>>> at
>>>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
>>>> Executor.java:635)
>>>> at
>>>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
>>>> ead.java:61)
>>>> at java.base/java.lang.Thread.run(Thread.java:833)
>>>>
>>>> I hope the stack shows the problem and helps to identify the problem.
>>>> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
>>>> http2 and is causing the issue.
>>>>
>>>> Thanks in advance!
>>>> Thomas
>>>>
>>>>> -----Ursprüngliche Nachricht-----
>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>> <Th...@speed4trade.com.INVALID>
>>>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>>>> connection with Firefox
>>>>>
>>>>> Oh... I also discovered an additional message in the wireshark dump.
>>>>> Tomcat replied with a goaway packet with the text:
>>>>> Connection [22], Stream [19], An error occurred during processing
>>>>> that was fatal to the connection
>>>>>
>>>>>> -----Ursprüngliche Nachricht-----
>>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>>> <Th...@speed4trade.com.INVALID>
>>>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>> closes connection with Firefox
>>>>>>
>>>>>> Hello Mark,
>>>>>>
>>>>>> I did some further investigations. I hope I don’t bother you with this
>>>> topic.
>>>>>>
>>>>>> I was trying to narrow down the tomcat version where the problem
>>>>>> started to appear.
>>>>>> The problem with the interrupted connection started with 10.0.0-M8
>>>>>> With Tomcat 10.0.0-M7 everything works fine.
>>>>>>
>>>>>> Comparing the sources, there are some (maybe relevant) changes in
>>>>>> the
>>>>>> org.apache.coyote.http2 package from M7 --> M8:
>>>>>> - Http2AsynUpgradeHandler
>>>>>> - Http2UpgradeHandler
>>>>>> - Stream
>>>>>> - StreamProcessor
>>>>>>
>>>>>> The observed problem was, that the browser (firefox) was sending a
>>>>>> RST_Stream packet to close a single stream within the http2 protocol
>>>>>> and tomcat was closing the whole connection instead of closing just
>>>>>> that stream (wireshark dump would be available).
>>>>>>
>>>>>> In Stream.java a new method "doStreamCancel" was introduced (or an
>>>>>> old method was renamed) with release M8.
>>>>>> This looks related to the observed problem mentioned above.
>>>>>>
>>>>>> Does this information help to take a look again at this problem?
>>>>>> If I should try something or can assist with testing, just let me know.
>>>>>>
>>>>>> Thanks!
>>>>>> Thomas
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>> -----Ursprüngliche Nachricht-----
>>>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>>>> <Th...@speed4trade.com.INVALID>
>>>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>>> closes connection with Firefox
>>>>>>>
>>>>>>> Hallo Mark,
>>>>>>>
>>>>>>>> -----Ursprüngliche Nachricht-----
>>>>>>>> Von: Mark Thomas <ma...@apache.org>
>>>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
>>>>>>>> An: users@tomcat.apache.org
>>>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>>>> closes connection with Firefox
>>>>>>>>
>>>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
>>>>>>>>
>>>>>>>> <snip/>
>>>>>>>>
>>>>>>>>> I think I'm going to need the sample app to investigate this.
>>>>>>>>
>>>>>>>> I have received the sample application and can recreate the issue.
>>>>>>>>
>>>>>>>> Going back to your original summary:
>>>>>>>>
>>>>>>>> <quote>
>>>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
>>>>>>>> 2) Tomcat sends the first compressed chunks of data to the
>>>>>>>> browser
>>>>>>>> 3) Firefox reads the first packages and notices, that additional
>>>>>>>> resources are needed (CSS, JS ...)
>>>>>>>> 4) While Tomcat is still sending the main page in chunks, the
>>>>>>>> browser is already requesting additional resources on other
>>>>>>>> channels
>>>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
>>>>>>>> requested
>>>>>>>> stream(s) (dunno why it does request first and then closes the
>>>>>>>> channel)
>>>>>>>> 6) Tomcat is sending a GoAway message to the browser
>>>>>>>> 7) Tomcat stops also sending the main page (on a different
>>>>>>>> channel) </quote>
>>>>>>>>
>>>>>>>> I tested with 10.0.x.
>>>>>>>>
>>>>>>>> I don't see the above sequence.
>>>>>>>>
>>>>>>>> I ran the test 4 times, closing the browser between each test
>>>>>>>>
>>>>>>>> When things go wrong it appears that FireFox is re-using the
>>>>>>>> main page
>>>>>>>> (ticket.jsp) from a cache.
>>>>>>>>
>>>>>>>> I see the additional resources being requested and then cancelled.
>>>>>>>>
>>>>>>>> I do not see any GOAWAY messages from Tomcat.
>>>>>>>>
>>>>>>>> I do see a single GOAWAY message from the browser to Tomcat
>>>> when
>>>>>>>> I close the browser window (as expected).
>>>>>>>>
>>>>>>>> I don't see anything going wrong on the Tomcat side.
>>>>>>>>
>>>>>>>> At the moment, this looks to me like an issue with Firefox
>>>>>>>> rather than with Tomcat.
>>>>>>>>
>>>>>>>> If you can narrow the test case to something that shows Tomcat
>>>>>>>> doing something wrong, then I'd be happy to look at this again.
>>>>>>>>
>>>>>>>> Mark
>>>>>>>>
>>>>>>>> ----------------------------------------------------------------
>>>>>>>> --
>>>>>>>> --
>>>>>>>> -
>>>>>>>
>>>>>>> Thank you very much for taking a look at it!
>>>>>>>
>>>>>>> I could also see that the browser cache is used sometimes.
>>>>>>> Sometimes the jsp is requested from the server, sometimes not.
>>>>>>>
>>>>>>> I did several tests again and the behaviour is not very
>>>>>>> consistent, thus it's hard to get a handle on the problem.
>>>>>>> I was also thinking about the possibility of a Firefox bug but
>>>>>>> this wouldn’t explain that:
>>>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
>>>>>>> Tomcat 9.x
>>>>>>> 2) Users don’t report any problems with other internet websites
>>>>>>> (using
>>>>>>> Firefox)
>>>>>>>
>>>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
>>>>>> always.
>>>>>>> I recorded one session which matches my last description:
>>>>>>> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
>>>>>>> I set up another PC for testing, thus the IP addresses
>>>>>>> (source/target) differ and can be interpreted more easily.
>>>>>>> Maybe the last Capture was not readable without the keyfile, thus
>>>>>>> I exported it differently and it should be readable now.
>>>>>>>
>>>>>>> a) Is the behaviour according to the linked network trace an
>>>>>>> expected behaviour? (sending a GoAway after a rst_stream message)
>>>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
>>>>>>>
>>>>>>> If you have any hints or suggestions, how I could narrow it down,
>>>>>>> please drop a line.
>>>>>>> I don’t have any big or great ideas at the moment.
>>>>>>>
>>>>>>> Thank you very much!
>>>>>>> Thomas
>>>>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
I will send you the log and access-log to your email address.
I am not sure whether it contradicts the observation.
For example:
- Browser opens a TCP-connection and requests the HTML page.
- Tomcat sends single packages with HTML via http2-stream no 1.
- Browser requests CSS via http2-stream no 2.
- Tomcat serves HTML via stream 1 and css via stream 2.
- Browser closes stream 2 which triggers tomcat to close the whole TCP connection including stream 1.
- Thus the html stream is also cancelled, leading to a partly visible html page.
I hope the logs will provide more information.
Thanks! Thomas
________________________________
Von: Mark Thomas <ma...@apache.org>
Gesendet: Dienstag, 20. September 2022 09:04
An: users@tomcat.apache.org
Betreff: Re: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
On 19/09/2022 19:19, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello Mark,
>
> thanks for the update.
>
> The commit looked promising. I tried with Tomcat 10.1 M17 but unfortunately it didn't help.
>
> The partly loaded website is still occuring.
>
>
> Setting http2 logging to fine, I can see the following stack:
That looks like the client reset the stream but that doesn't match what
you are observing which sounds like Tomcat is truncating the response.
> 19-Sep-2022 20:07:16.651 FEIN [https-openssl-nio-443-exec-9] org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW] reported while processing request
> org.apache.coyote.CloseNowException: Connection [1], Stream [23], This stream is not writable
That this is happening with connection 1 is good. It means it should be
easy to reproduce. Please can you:
- enable debug logging for HTTP/2
- restart Tomcat
- trigger this problem
- provide the full debug logs
I want to trace what is happening on the HTTP/2 connection leading up to
the truncation occurring.
Thanks,
Mark
> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:258)
> at org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:919)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:945)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:891)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:990)
> at org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java:128)
> at org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71)
> at org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:230)
> at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:391)
> at org.apache.coyote.Response.action(Response.java:210)
> at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:258)
> at org.apache.catalina.connector.Response.finishResponse(Response.java:418)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:388)
> at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
> at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
> at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:87)
> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> 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:833)
> Caused by: org.apache.coyote.http2.StreamException: Connection [1], Stream [23], This stream is not writable
> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:250)
> ... 20 more
>
>
>
> Looks like the Exception bubbles up from the last line of tthis method:
>
> void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
> StreamException se = new StreamException(msg, error, getIdAsInt());
> // Prevent the application making further writes
> streamOutputBuffer.closed = true;
> // Prevent Tomcat's error handling trying to write
> coyoteResponse.setError();
> coyoteResponse.setErrorReported();
> // Trigger a reset once control returns to Tomcat
> streamOutputBuffer.reset = se;
> throw new CloseNowException(msg, se);
> }
>
> The CloseNowException() bubbles up without being caught maybe (?)
> Stream.write(...) is not contained here.
>
> Greetings, Thoas
>
> ________________________________
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Montag, 19. September 2022 19:22
> An: users@tomcat.apache.org
> Betreff: Re: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
>
> Thomas,
>
> Please update to the latest 10.1.x release and re-test. There is what
> looks like a fix for this issue in 10.1.0-M12:
>
> https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95c982827e9753dd
>
> Mark
>
>
> On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>> Hello,
>>
>> I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
>>
>> Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
>> In the first case it leads to closing the complete TCP connection.
>>
>> Thanks! Thomas
>>
>>
>>> -----Ursprüngliche Nachricht-----
>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>> <Th...@speed4trade.com.INVALID>
>>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>> connection with Firefox
>>>
>>> Hello Mark,
>>>
>>> I got a stack trace which also shows the involvement of the gzip filter. I set
>>> the loglevel for the http2-StreamProcessor to get the details.
>>> The stack trace was written when the problem with FF occurred.
>>> FF closed one single stream in http2 connection and tomcat seemed to have
>>> closed the whole TCP connection:
>>>
>>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
>>> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
>>> [23], An error occurred during processing that was fatal to the connection
>>> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
>>> to write to stream once it has been closed
>>> at
>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
>>> 880)
>>> at
>>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
>>> GzipOutputFilter.java:158)
>>> at
>>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
>>> )
>>> at
>>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
>>> :125)
>>> at
>>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
>>> )
>>> at
>>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
>>> java:209)
>>> at
>>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>>> at
>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
>>> )
>>> at
>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
>>> va:65)
>>> at
>>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
>>> )
>>> at
>>> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>>> at
>>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
>>> xecutor.java:1136)
>>> at
>>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
>>> Executor.java:635)
>>> at
>>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
>>> ead.java:61)
>>> at java.base/java.lang.Thread.run(Thread.java:833)
>>>
>>> I hope the stack shows the problem and helps to identify the problem.
>>> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
>>> http2 and is causing the issue.
>>>
>>> Thanks in advance!
>>> Thomas
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>> <Th...@speed4trade.com.INVALID>
>>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>>> connection with Firefox
>>>>
>>>> Oh... I also discovered an additional message in the wireshark dump.
>>>> Tomcat replied with a goaway packet with the text:
>>>> Connection [22], Stream [19], An error occurred during processing
>>>> that was fatal to the connection
>>>>
>>>>> -----Ursprüngliche Nachricht-----
>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>> <Th...@speed4trade.com.INVALID>
>>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>> closes connection with Firefox
>>>>>
>>>>> Hello Mark,
>>>>>
>>>>> I did some further investigations. I hope I don’t bother you with this
>>> topic.
>>>>>
>>>>> I was trying to narrow down the tomcat version where the problem
>>>>> started to appear.
>>>>> The problem with the interrupted connection started with 10.0.0-M8
>>>>> With Tomcat 10.0.0-M7 everything works fine.
>>>>>
>>>>> Comparing the sources, there are some (maybe relevant) changes in
>>>>> the
>>>>> org.apache.coyote.http2 package from M7 --> M8:
>>>>> - Http2AsynUpgradeHandler
>>>>> - Http2UpgradeHandler
>>>>> - Stream
>>>>> - StreamProcessor
>>>>>
>>>>> The observed problem was, that the browser (firefox) was sending a
>>>>> RST_Stream packet to close a single stream within the http2 protocol
>>>>> and tomcat was closing the whole connection instead of closing just
>>>>> that stream (wireshark dump would be available).
>>>>>
>>>>> In Stream.java a new method "doStreamCancel" was introduced (or an
>>>>> old method was renamed) with release M8.
>>>>> This looks related to the observed problem mentioned above.
>>>>>
>>>>> Does this information help to take a look again at this problem?
>>>>> If I should try something or can assist with testing, just let me know.
>>>>>
>>>>> Thanks!
>>>>> Thomas
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>> -----Ursprüngliche Nachricht-----
>>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>>> <Th...@speed4trade.com.INVALID>
>>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>> closes connection with Firefox
>>>>>>
>>>>>> Hallo Mark,
>>>>>>
>>>>>>> -----Ursprüngliche Nachricht-----
>>>>>>> Von: Mark Thomas <ma...@apache.org>
>>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
>>>>>>> An: users@tomcat.apache.org
>>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>>> closes connection with Firefox
>>>>>>>
>>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
>>>>>>>
>>>>>>> <snip/>
>>>>>>>
>>>>>>>> I think I'm going to need the sample app to investigate this.
>>>>>>>
>>>>>>> I have received the sample application and can recreate the issue.
>>>>>>>
>>>>>>> Going back to your original summary:
>>>>>>>
>>>>>>> <quote>
>>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
>>>>>>> 2) Tomcat sends the first compressed chunks of data to the
>>>>>>> browser
>>>>>>> 3) Firefox reads the first packages and notices, that additional
>>>>>>> resources are needed (CSS, JS ...)
>>>>>>> 4) While Tomcat is still sending the main page in chunks, the
>>>>>>> browser is already requesting additional resources on other
>>>>>>> channels
>>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
>>>>>>> requested
>>>>>>> stream(s) (dunno why it does request first and then closes the
>>>>>>> channel)
>>>>>>> 6) Tomcat is sending a GoAway message to the browser
>>>>>>> 7) Tomcat stops also sending the main page (on a different
>>>>>>> channel) </quote>
>>>>>>>
>>>>>>> I tested with 10.0.x.
>>>>>>>
>>>>>>> I don't see the above sequence.
>>>>>>>
>>>>>>> I ran the test 4 times, closing the browser between each test
>>>>>>>
>>>>>>> When things go wrong it appears that FireFox is re-using the
>>>>>>> main page
>>>>>>> (ticket.jsp) from a cache.
>>>>>>>
>>>>>>> I see the additional resources being requested and then cancelled.
>>>>>>>
>>>>>>> I do not see any GOAWAY messages from Tomcat.
>>>>>>>
>>>>>>> I do see a single GOAWAY message from the browser to Tomcat
>>> when
>>>>>>> I close the browser window (as expected).
>>>>>>>
>>>>>>> I don't see anything going wrong on the Tomcat side.
>>>>>>>
>>>>>>> At the moment, this looks to me like an issue with Firefox
>>>>>>> rather than with Tomcat.
>>>>>>>
>>>>>>> If you can narrow the test case to something that shows Tomcat
>>>>>>> doing something wrong, then I'd be happy to look at this again.
>>>>>>>
>>>>>>> Mark
>>>>>>>
>>>>>>> ----------------------------------------------------------------
>>>>>>> --
>>>>>>> --
>>>>>>> -
>>>>>>
>>>>>> Thank you very much for taking a look at it!
>>>>>>
>>>>>> I could also see that the browser cache is used sometimes.
>>>>>> Sometimes the jsp is requested from the server, sometimes not.
>>>>>>
>>>>>> I did several tests again and the behaviour is not very
>>>>>> consistent, thus it's hard to get a handle on the problem.
>>>>>> I was also thinking about the possibility of a Firefox bug but
>>>>>> this wouldn’t explain that:
>>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
>>>>>> Tomcat 9.x
>>>>>> 2) Users don’t report any problems with other internet websites
>>>>>> (using
>>>>>> Firefox)
>>>>>>
>>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
>>>>> always.
>>>>>> I recorded one session which matches my last description:
>>>>>> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
>>>>>> I set up another PC for testing, thus the IP addresses
>>>>>> (source/target) differ and can be interpreted more easily.
>>>>>> Maybe the last Capture was not readable without the keyfile, thus
>>>>>> I exported it differently and it should be readable now.
>>>>>>
>>>>>> a) Is the behaviour according to the linked network trace an
>>>>>> expected behaviour? (sending a GoAway after a rst_stream message)
>>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
>>>>>>
>>>>>> If you have any hints or suggestions, how I could narrow it down,
>>>>>> please drop a line.
>>>>>> I don’t have any big or great ideas at the moment.
>>>>>>
>>>>>> Thank you very much!
>>>>>> Thomas
>>>>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by Mark Thomas <ma...@apache.org>.
On 19/09/2022 19:19, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello Mark,
>
> thanks for the update.
>
> The commit looked promising. I tried with Tomcat 10.1 M17 but unfortunately it didn't help.
>
> The partly loaded website is still occuring.
>
>
> Setting http2 logging to fine, I can see the following stack:
That looks like the client reset the stream but that doesn't match what
you are observing which sounds like Tomcat is truncating the response.
> 19-Sep-2022 20:07:16.651 FEIN [https-openssl-nio-443-exec-9] org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW] reported while processing request
> org.apache.coyote.CloseNowException: Connection [1], Stream [23], This stream is not writable
That this is happening with connection 1 is good. It means it should be
easy to reproduce. Please can you:
- enable debug logging for HTTP/2
- restart Tomcat
- trigger this problem
- provide the full debug logs
I want to trace what is happening on the HTTP/2 connection leading up to
the truncation occurring.
Thanks,
Mark
> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:258)
> at org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:919)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:945)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:891)
> at org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:990)
> at org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java:128)
> at org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71)
> at org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:230)
> at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:391)
> at org.apache.coyote.Response.action(Response.java:210)
> at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:258)
> at org.apache.catalina.connector.Response.finishResponse(Response.java:418)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:388)
> at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
> at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
> at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:87)
> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> 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:833)
> Caused by: org.apache.coyote.http2.StreamException: Connection [1], Stream [23], This stream is not writable
> at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:250)
> ... 20 more
>
>
>
> Looks like the Exception bubbles up from the last line of tthis method:
>
> void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
> StreamException se = new StreamException(msg, error, getIdAsInt());
> // Prevent the application making further writes
> streamOutputBuffer.closed = true;
> // Prevent Tomcat's error handling trying to write
> coyoteResponse.setError();
> coyoteResponse.setErrorReported();
> // Trigger a reset once control returns to Tomcat
> streamOutputBuffer.reset = se;
> throw new CloseNowException(msg, se);
> }
>
> The CloseNowException() bubbles up without being caught maybe (?)
> Stream.write(...) is not contained here.
>
> Greetings, Thoas
>
> ________________________________
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Montag, 19. September 2022 19:22
> An: users@tomcat.apache.org
> Betreff: Re: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
>
> Thomas,
>
> Please update to the latest 10.1.x release and re-test. There is what
> looks like a fix for this issue in 10.1.0-M12:
>
> https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95c982827e9753dd
>
> Mark
>
>
> On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
>> Hello,
>>
>> I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
>>
>> Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
>> In the first case it leads to closing the complete TCP connection.
>>
>> Thanks! Thomas
>>
>>
>>> -----Ursprüngliche Nachricht-----
>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>> <Th...@speed4trade.com.INVALID>
>>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>> connection with Firefox
>>>
>>> Hello Mark,
>>>
>>> I got a stack trace which also shows the involvement of the gzip filter. I set
>>> the loglevel for the http2-StreamProcessor to get the details.
>>> The stack trace was written when the problem with FF occurred.
>>> FF closed one single stream in http2 connection and tomcat seemed to have
>>> closed the whole TCP connection:
>>>
>>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
>>> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
>>> [23], An error occurred during processing that was fatal to the connection
>>> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
>>> to write to stream once it has been closed
>>> at
>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
>>> 880)
>>> at
>>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
>>> GzipOutputFilter.java:158)
>>> at
>>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
>>> )
>>> at
>>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
>>> :125)
>>> at
>>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
>>> )
>>> at
>>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
>>> java:209)
>>> at
>>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>>> at
>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
>>> )
>>> at
>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
>>> va:65)
>>> at
>>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
>>> )
>>> at
>>> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>>> at
>>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
>>> xecutor.java:1136)
>>> at
>>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
>>> Executor.java:635)
>>> at
>>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
>>> ead.java:61)
>>> at java.base/java.lang.Thread.run(Thread.java:833)
>>>
>>> I hope the stack shows the problem and helps to identify the problem.
>>> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
>>> http2 and is causing the issue.
>>>
>>> Thanks in advance!
>>> Thomas
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>> <Th...@speed4trade.com.INVALID>
>>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>>> connection with Firefox
>>>>
>>>> Oh... I also discovered an additional message in the wireshark dump.
>>>> Tomcat replied with a goaway packet with the text:
>>>> Connection [22], Stream [19], An error occurred during processing
>>>> that was fatal to the connection
>>>>
>>>>> -----Ursprüngliche Nachricht-----
>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>> <Th...@speed4trade.com.INVALID>
>>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>> closes connection with Firefox
>>>>>
>>>>> Hello Mark,
>>>>>
>>>>> I did some further investigations. I hope I don’t bother you with this
>>> topic.
>>>>>
>>>>> I was trying to narrow down the tomcat version where the problem
>>>>> started to appear.
>>>>> The problem with the interrupted connection started with 10.0.0-M8
>>>>> With Tomcat 10.0.0-M7 everything works fine.
>>>>>
>>>>> Comparing the sources, there are some (maybe relevant) changes in
>>>>> the
>>>>> org.apache.coyote.http2 package from M7 --> M8:
>>>>> - Http2AsynUpgradeHandler
>>>>> - Http2UpgradeHandler
>>>>> - Stream
>>>>> - StreamProcessor
>>>>>
>>>>> The observed problem was, that the browser (firefox) was sending a
>>>>> RST_Stream packet to close a single stream within the http2 protocol
>>>>> and tomcat was closing the whole connection instead of closing just
>>>>> that stream (wireshark dump would be available).
>>>>>
>>>>> In Stream.java a new method "doStreamCancel" was introduced (or an
>>>>> old method was renamed) with release M8.
>>>>> This looks related to the observed problem mentioned above.
>>>>>
>>>>> Does this information help to take a look again at this problem?
>>>>> If I should try something or can assist with testing, just let me know.
>>>>>
>>>>> Thanks!
>>>>> Thomas
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>> -----Ursprüngliche Nachricht-----
>>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>>> <Th...@speed4trade.com.INVALID>
>>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>> closes connection with Firefox
>>>>>>
>>>>>> Hallo Mark,
>>>>>>
>>>>>>> -----Ursprüngliche Nachricht-----
>>>>>>> Von: Mark Thomas <ma...@apache.org>
>>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
>>>>>>> An: users@tomcat.apache.org
>>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>>> closes connection with Firefox
>>>>>>>
>>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
>>>>>>>
>>>>>>> <snip/>
>>>>>>>
>>>>>>>> I think I'm going to need the sample app to investigate this.
>>>>>>>
>>>>>>> I have received the sample application and can recreate the issue.
>>>>>>>
>>>>>>> Going back to your original summary:
>>>>>>>
>>>>>>> <quote>
>>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
>>>>>>> 2) Tomcat sends the first compressed chunks of data to the
>>>>>>> browser
>>>>>>> 3) Firefox reads the first packages and notices, that additional
>>>>>>> resources are needed (CSS, JS ...)
>>>>>>> 4) While Tomcat is still sending the main page in chunks, the
>>>>>>> browser is already requesting additional resources on other
>>>>>>> channels
>>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
>>>>>>> requested
>>>>>>> stream(s) (dunno why it does request first and then closes the
>>>>>>> channel)
>>>>>>> 6) Tomcat is sending a GoAway message to the browser
>>>>>>> 7) Tomcat stops also sending the main page (on a different
>>>>>>> channel) </quote>
>>>>>>>
>>>>>>> I tested with 10.0.x.
>>>>>>>
>>>>>>> I don't see the above sequence.
>>>>>>>
>>>>>>> I ran the test 4 times, closing the browser between each test
>>>>>>>
>>>>>>> When things go wrong it appears that FireFox is re-using the
>>>>>>> main page
>>>>>>> (ticket.jsp) from a cache.
>>>>>>>
>>>>>>> I see the additional resources being requested and then cancelled.
>>>>>>>
>>>>>>> I do not see any GOAWAY messages from Tomcat.
>>>>>>>
>>>>>>> I do see a single GOAWAY message from the browser to Tomcat
>>> when
>>>>>>> I close the browser window (as expected).
>>>>>>>
>>>>>>> I don't see anything going wrong on the Tomcat side.
>>>>>>>
>>>>>>> At the moment, this looks to me like an issue with Firefox
>>>>>>> rather than with Tomcat.
>>>>>>>
>>>>>>> If you can narrow the test case to something that shows Tomcat
>>>>>>> doing something wrong, then I'd be happy to look at this again.
>>>>>>>
>>>>>>> Mark
>>>>>>>
>>>>>>> ----------------------------------------------------------------
>>>>>>> --
>>>>>>> --
>>>>>>> -
>>>>>>
>>>>>> Thank you very much for taking a look at it!
>>>>>>
>>>>>> I could also see that the browser cache is used sometimes.
>>>>>> Sometimes the jsp is requested from the server, sometimes not.
>>>>>>
>>>>>> I did several tests again and the behaviour is not very
>>>>>> consistent, thus it's hard to get a handle on the problem.
>>>>>> I was also thinking about the possibility of a Firefox bug but
>>>>>> this wouldn’t explain that:
>>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
>>>>>> Tomcat 9.x
>>>>>> 2) Users don’t report any problems with other internet websites
>>>>>> (using
>>>>>> Firefox)
>>>>>>
>>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
>>>>> always.
>>>>>> I recorded one session which matches my last description:
>>>>>> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
>>>>>> I set up another PC for testing, thus the IP addresses
>>>>>> (source/target) differ and can be interpreted more easily.
>>>>>> Maybe the last Capture was not readable without the keyfile, thus
>>>>>> I exported it differently and it should be readable now.
>>>>>>
>>>>>> a) Is the behaviour according to the linked network trace an
>>>>>> expected behaviour? (sending a GoAway after a rst_stream message)
>>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
>>>>>>
>>>>>> If you have any hints or suggestions, how I could narrow it down,
>>>>>> please drop a line.
>>>>>> I don’t have any big or great ideas at the moment.
>>>>>>
>>>>>> Thank you very much!
>>>>>> Thomas
>>>>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
thanks for the update.
The commit looked promising. I tried with Tomcat 10.1 M17 but unfortunately it didn't help.
The partly loaded website is still occuring.
Setting http2 logging to fine, I can see the following stack:
19-Sep-2022 20:07:16.651 FEIN [https-openssl-nio-443-exec-9] org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW] reported while processing request
org.apache.coyote.CloseNowException: Connection [1], Stream [23], This stream is not writable
at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:258)
at org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:919)
at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:945)
at org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:891)
at org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:990)
at org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java:128)
at org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71)
at org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:230)
at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:391)
at org.apache.coyote.Response.action(Response.java:210)
at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:258)
at org.apache.catalina.connector.Response.finishResponse(Response.java:418)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:388)
at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:87)
at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
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:833)
Caused by: org.apache.coyote.http2.StreamException: Connection [1], Stream [23], This stream is not writable
at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:250)
... 20 more
Looks like the Exception bubbles up from the last line of tthis method:
void doStreamCancel(String msg, Http2Error error) throws CloseNowException {
StreamException se = new StreamException(msg, error, getIdAsInt());
// Prevent the application making further writes
streamOutputBuffer.closed = true;
// Prevent Tomcat's error handling trying to write
coyoteResponse.setError();
coyoteResponse.setErrorReported();
// Trigger a reset once control returns to Tomcat
streamOutputBuffer.reset = se;
throw new CloseNowException(msg, se);
}
The CloseNowException() bubbles up without being caught maybe (?)
Stream.write(...) is not contained here.
Greetings, Thoas
________________________________
Von: Mark Thomas <ma...@apache.org>
Gesendet: Montag, 19. September 2022 19:22
An: users@tomcat.apache.org
Betreff: Re: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Thomas,
Please update to the latest 10.1.x release and re-test. There is what
looks like a fix for this issue in 10.1.0-M12:
https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95c982827e9753dd
Mark
On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello,
>
> I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
>
> Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
> In the first case it leads to closing the complete TCP connection.
>
> Thanks! Thomas
>
>
>> -----Ursprüngliche Nachricht-----
>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>> <Th...@speed4trade.com.INVALID>
>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>> An: Tomcat Users List <us...@tomcat.apache.org>
>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>> connection with Firefox
>>
>> Hello Mark,
>>
>> I got a stack trace which also shows the involvement of the gzip filter. I set
>> the loglevel for the http2-StreamProcessor to get the details.
>> The stack trace was written when the problem with FF occurred.
>> FF closed one single stream in http2 connection and tomcat seemed to have
>> closed the whole TCP connection:
>>
>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
>> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
>> [23], An error occurred during processing that was fatal to the connection
>> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
>> to write to stream once it has been closed
>> at
>> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
>> 880)
>> at
>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
>> GzipOutputFilter.java:158)
>> at
>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
>> )
>> at
>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
>> :125)
>> at
>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
>> )
>> at
>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
>> java:209)
>> at
>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>> at
>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
>> )
>> at
>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
>> va:65)
>> at
>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
>> )
>> at
>> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>> at
>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
>> xecutor.java:1136)
>> at
>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
>> Executor.java:635)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
>> ead.java:61)
>> at java.base/java.lang.Thread.run(Thread.java:833)
>>
>> I hope the stack shows the problem and helps to identify the problem.
>> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
>> http2 and is causing the issue.
>>
>> Thanks in advance!
>> Thomas
>>
>>> -----Ursprüngliche Nachricht-----
>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>> <Th...@speed4trade.com.INVALID>
>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>> connection with Firefox
>>>
>>> Oh... I also discovered an additional message in the wireshark dump.
>>> Tomcat replied with a goaway packet with the text:
>>> Connection [22], Stream [19], An error occurred during processing
>>> that was fatal to the connection
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>> <Th...@speed4trade.com.INVALID>
>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>> closes connection with Firefox
>>>>
>>>> Hello Mark,
>>>>
>>>> I did some further investigations. I hope I don’t bother you with this
>> topic.
>>>>
>>>> I was trying to narrow down the tomcat version where the problem
>>>> started to appear.
>>>> The problem with the interrupted connection started with 10.0.0-M8
>>>> With Tomcat 10.0.0-M7 everything works fine.
>>>>
>>>> Comparing the sources, there are some (maybe relevant) changes in
>>>> the
>>>> org.apache.coyote.http2 package from M7 --> M8:
>>>> - Http2AsynUpgradeHandler
>>>> - Http2UpgradeHandler
>>>> - Stream
>>>> - StreamProcessor
>>>>
>>>> The observed problem was, that the browser (firefox) was sending a
>>>> RST_Stream packet to close a single stream within the http2 protocol
>>>> and tomcat was closing the whole connection instead of closing just
>>>> that stream (wireshark dump would be available).
>>>>
>>>> In Stream.java a new method "doStreamCancel" was introduced (or an
>>>> old method was renamed) with release M8.
>>>> This looks related to the observed problem mentioned above.
>>>>
>>>> Does this information help to take a look again at this problem?
>>>> If I should try something or can assist with testing, just let me know.
>>>>
>>>> Thanks!
>>>> Thomas
>>>>
>>>>
>>>>
>>>>
>>>>> -----Ursprüngliche Nachricht-----
>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>> <Th...@speed4trade.com.INVALID>
>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>> closes connection with Firefox
>>>>>
>>>>> Hallo Mark,
>>>>>
>>>>>> -----Ursprüngliche Nachricht-----
>>>>>> Von: Mark Thomas <ma...@apache.org>
>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
>>>>>> An: users@tomcat.apache.org
>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>> closes connection with Firefox
>>>>>>
>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
>>>>>>
>>>>>> <snip/>
>>>>>>
>>>>>>> I think I'm going to need the sample app to investigate this.
>>>>>>
>>>>>> I have received the sample application and can recreate the issue.
>>>>>>
>>>>>> Going back to your original summary:
>>>>>>
>>>>>> <quote>
>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
>>>>>> 2) Tomcat sends the first compressed chunks of data to the
>>>>>> browser
>>>>>> 3) Firefox reads the first packages and notices, that additional
>>>>>> resources are needed (CSS, JS ...)
>>>>>> 4) While Tomcat is still sending the main page in chunks, the
>>>>>> browser is already requesting additional resources on other
>>>>>> channels
>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
>>>>>> requested
>>>>>> stream(s) (dunno why it does request first and then closes the
>>>>>> channel)
>>>>>> 6) Tomcat is sending a GoAway message to the browser
>>>>>> 7) Tomcat stops also sending the main page (on a different
>>>>>> channel) </quote>
>>>>>>
>>>>>> I tested with 10.0.x.
>>>>>>
>>>>>> I don't see the above sequence.
>>>>>>
>>>>>> I ran the test 4 times, closing the browser between each test
>>>>>>
>>>>>> When things go wrong it appears that FireFox is re-using the
>>>>>> main page
>>>>>> (ticket.jsp) from a cache.
>>>>>>
>>>>>> I see the additional resources being requested and then cancelled.
>>>>>>
>>>>>> I do not see any GOAWAY messages from Tomcat.
>>>>>>
>>>>>> I do see a single GOAWAY message from the browser to Tomcat
>> when
>>>>>> I close the browser window (as expected).
>>>>>>
>>>>>> I don't see anything going wrong on the Tomcat side.
>>>>>>
>>>>>> At the moment, this looks to me like an issue with Firefox
>>>>>> rather than with Tomcat.
>>>>>>
>>>>>> If you can narrow the test case to something that shows Tomcat
>>>>>> doing something wrong, then I'd be happy to look at this again.
>>>>>>
>>>>>> Mark
>>>>>>
>>>>>> ----------------------------------------------------------------
>>>>>> --
>>>>>> --
>>>>>> -
>>>>>
>>>>> Thank you very much for taking a look at it!
>>>>>
>>>>> I could also see that the browser cache is used sometimes.
>>>>> Sometimes the jsp is requested from the server, sometimes not.
>>>>>
>>>>> I did several tests again and the behaviour is not very
>>>>> consistent, thus it's hard to get a handle on the problem.
>>>>> I was also thinking about the possibility of a Firefox bug but
>>>>> this wouldn’t explain that:
>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
>>>>> Tomcat 9.x
>>>>> 2) Users don’t report any problems with other internet websites
>>>>> (using
>>>>> Firefox)
>>>>>
>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
>>>> always.
>>>>> I recorded one session which matches my last description:
>>>>> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
>>>>> I set up another PC for testing, thus the IP addresses
>>>>> (source/target) differ and can be interpreted more easily.
>>>>> Maybe the last Capture was not readable without the keyfile, thus
>>>>> I exported it differently and it should be readable now.
>>>>>
>>>>> a) Is the behaviour according to the linked network trace an
>>>>> expected behaviour? (sending a GoAway after a rst_stream message)
>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
>>>>>
>>>>> If you have any hints or suggestions, how I could narrow it down,
>>>>> please drop a line.
>>>>> I don’t have any big or great ideas at the moment.
>>>>>
>>>>> Thank you very much!
>>>>> Thomas
>>>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by Mark Thomas <ma...@apache.org>.
Thomas,
Please update to the latest 10.1.x release and re-test. There is what
looks like a fix for this issue in 10.1.0-M12:
https://github.com/apache/tomcat/commit/b738fa6ee0e6789b104e652d95c982827e9753dd
Mark
On 01/08/2022 21:46, Thomas Hoffmann (Speed4Trade GmbH) wrote:
> Hello,
>
> I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
>
> Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
> In the first case it leads to closing the complete TCP connection.
>
> Thanks! Thomas
>
>
>> -----Ursprüngliche Nachricht-----
>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>> <Th...@speed4trade.com.INVALID>
>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>> An: Tomcat Users List <us...@tomcat.apache.org>
>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>> connection with Firefox
>>
>> Hello Mark,
>>
>> I got a stack trace which also shows the involvement of the gzip filter. I set
>> the loglevel for the http2-StreamProcessor to get the details.
>> The stack trace was written when the problem with FF occurred.
>> FF closed one single stream in http2 connection and tomcat seemed to have
>> closed the whole TCP connection:
>>
>> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
>> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
>> [23], An error occurred during processing that was fatal to the connection
>> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
>> to write to stream once it has been closed
>> at
>> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
>> 880)
>> at
>> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
>> GzipOutputFilter.java:158)
>> at
>> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
>> )
>> at
>> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
>> :125)
>> at
>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
>> )
>> at
>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
>> java:209)
>> at
>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>> at
>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
>> )
>> at
>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
>> va:65)
>> at
>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
>> )
>> at
>> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>> at
>> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
>> xecutor.java:1136)
>> at
>> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
>> Executor.java:635)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
>> ead.java:61)
>> at java.base/java.lang.Thread.run(Thread.java:833)
>>
>> I hope the stack shows the problem and helps to identify the problem.
>> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
>> http2 and is causing the issue.
>>
>> Thanks in advance!
>> Thomas
>>
>>> -----Ursprüngliche Nachricht-----
>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>> <Th...@speed4trade.com.INVALID>
>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
>>> connection with Firefox
>>>
>>> Oh... I also discovered an additional message in the wireshark dump.
>>> Tomcat replied with a goaway packet with the text:
>>> Connection [22], Stream [19], An error occurred during processing
>>> that was fatal to the connection
>>>
>>>> -----Ursprüngliche Nachricht-----
>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>> <Th...@speed4trade.com.INVALID>
>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>> closes connection with Firefox
>>>>
>>>> Hello Mark,
>>>>
>>>> I did some further investigations. I hope I don’t bother you with this
>> topic.
>>>>
>>>> I was trying to narrow down the tomcat version where the problem
>>>> started to appear.
>>>> The problem with the interrupted connection started with 10.0.0-M8
>>>> With Tomcat 10.0.0-M7 everything works fine.
>>>>
>>>> Comparing the sources, there are some (maybe relevant) changes in
>>>> the
>>>> org.apache.coyote.http2 package from M7 --> M8:
>>>> - Http2AsynUpgradeHandler
>>>> - Http2UpgradeHandler
>>>> - Stream
>>>> - StreamProcessor
>>>>
>>>> The observed problem was, that the browser (firefox) was sending a
>>>> RST_Stream packet to close a single stream within the http2 protocol
>>>> and tomcat was closing the whole connection instead of closing just
>>>> that stream (wireshark dump would be available).
>>>>
>>>> In Stream.java a new method "doStreamCancel" was introduced (or an
>>>> old method was renamed) with release M8.
>>>> This looks related to the observed problem mentioned above.
>>>>
>>>> Does this information help to take a look again at this problem?
>>>> If I should try something or can assist with testing, just let me know.
>>>>
>>>> Thanks!
>>>> Thomas
>>>>
>>>>
>>>>
>>>>
>>>>> -----Ursprüngliche Nachricht-----
>>>>> Von: Thomas Hoffmann (Speed4Trade GmbH)
>>>>> <Th...@speed4trade.com.INVALID>
>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>> An: Tomcat Users List <us...@tomcat.apache.org>
>>>>> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
>>>>> closes connection with Firefox
>>>>>
>>>>> Hallo Mark,
>>>>>
>>>>>> -----Ursprüngliche Nachricht-----
>>>>>> Von: Mark Thomas <ma...@apache.org>
>>>>>> Gesendet: Montag, 4. Juli 2022 19:37
>>>>>> An: users@tomcat.apache.org
>>>>>> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
>>>>>> closes connection with Firefox
>>>>>>
>>>>>> On 30/06/2022 07:40, Mark Thomas wrote:
>>>>>>
>>>>>> <snip/>
>>>>>>
>>>>>>> I think I'm going to need the sample app to investigate this.
>>>>>>
>>>>>> I have received the sample application and can recreate the issue.
>>>>>>
>>>>>> Going back to your original summary:
>>>>>>
>>>>>> <quote>
>>>>>> 1) Main page was requested by Firefox from Tomcat (GET ...)
>>>>>> 2) Tomcat sends the first compressed chunks of data to the
>>>>>> browser
>>>>>> 3) Firefox reads the first packages and notices, that additional
>>>>>> resources are needed (CSS, JS ...)
>>>>>> 4) While Tomcat is still sending the main page in chunks, the
>>>>>> browser is already requesting additional resources on other
>>>>>> channels
>>>>>> 5) Firefox is sending a RST_STREAM and closes that last
>>>>>> requested
>>>>>> stream(s) (dunno why it does request first and then closes the
>>>>>> channel)
>>>>>> 6) Tomcat is sending a GoAway message to the browser
>>>>>> 7) Tomcat stops also sending the main page (on a different
>>>>>> channel) </quote>
>>>>>>
>>>>>> I tested with 10.0.x.
>>>>>>
>>>>>> I don't see the above sequence.
>>>>>>
>>>>>> I ran the test 4 times, closing the browser between each test
>>>>>>
>>>>>> When things go wrong it appears that FireFox is re-using the
>>>>>> main page
>>>>>> (ticket.jsp) from a cache.
>>>>>>
>>>>>> I see the additional resources being requested and then cancelled.
>>>>>>
>>>>>> I do not see any GOAWAY messages from Tomcat.
>>>>>>
>>>>>> I do see a single GOAWAY message from the browser to Tomcat
>> when
>>>>>> I close the browser window (as expected).
>>>>>>
>>>>>> I don't see anything going wrong on the Tomcat side.
>>>>>>
>>>>>> At the moment, this looks to me like an issue with Firefox
>>>>>> rather than with Tomcat.
>>>>>>
>>>>>> If you can narrow the test case to something that shows Tomcat
>>>>>> doing something wrong, then I'd be happy to look at this again.
>>>>>>
>>>>>> Mark
>>>>>>
>>>>>> ----------------------------------------------------------------
>>>>>> --
>>>>>> --
>>>>>> -
>>>>>
>>>>> Thank you very much for taking a look at it!
>>>>>
>>>>> I could also see that the browser cache is used sometimes.
>>>>> Sometimes the jsp is requested from the server, sometimes not.
>>>>>
>>>>> I did several tests again and the behaviour is not very
>>>>> consistent, thus it's hard to get a handle on the problem.
>>>>> I was also thinking about the possibility of a Firefox bug but
>>>>> this wouldn’t explain that:
>>>>> 1) It only happens with Tomcat 10.x and doesn’t show up with
>>>>> Tomcat 9.x
>>>>> 2) Users don’t report any problems with other internet websites
>>>>> (using
>>>>> Firefox)
>>>>>
>>>>> The GoAway seems to be sent from time to time by Tomcat, but not
>>>> always.
>>>>> I recorded one session which matches my last description:
>>>>> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
>>>>> I set up another PC for testing, thus the IP addresses
>>>>> (source/target) differ and can be interpreted more easily.
>>>>> Maybe the last Capture was not readable without the keyfile, thus
>>>>> I exported it differently and it should be readable now.
>>>>>
>>>>> a) Is the behaviour according to the linked network trace an
>>>>> expected behaviour? (sending a GoAway after a rst_stream message)
>>>>> b) Have you been able to reproduce the error with Tomcat 9.x?
>>>>>
>>>>> If you have any hints or suggestions, how I could narrow it down,
>>>>> please drop a line.
>>>>> I don’t have any big or great ideas at the moment.
>>>>>
>>>>> Thank you very much!
>>>>> Thomas
>>>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello,
I would create a ticket and sum up all the collected information about this issue, if there are no further suggestions.
Closing a single stream in http2 causes an internal exception in StreamProcessor which bubbles up in different ways, depending whether http-compression is active or not.
In the first case it leads to closing the complete TCP connection.
Thanks! Thomas
> -----Ursprüngliche Nachricht-----
> Von: Thomas Hoffmann (Speed4Trade GmbH)
> <Th...@speed4trade.com.INVALID>
> Gesendet: Donnerstag, 28. Juli 2022 22:25
> An: Tomcat Users List <us...@tomcat.apache.org>
> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> connection with Firefox
>
> Hello Mark,
>
> I got a stack trace which also shows the involvement of the gzip filter. I set
> the loglevel for the http2-StreamProcessor to get the details.
> The stack trace was written when the problem with FF occurred.
> FF closed one single stream in http2 connection and tomcat seemed to have
> closed the whole TCP connection:
>
> 28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13]
> org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream
> [23], An error occurred during processing that was fatal to the connection
> java.lang.IllegalStateException: Connection [0], Stream [23], Unable
> to write to stream once it has been closed
> at
> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
> 880)
> at
> org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(
> GzipOutputFilter.java:158)
> at
> java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171
> )
> at
> org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java
> :125)
> at
> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71
> )
> at
> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.
> java:209)
> at
> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
> at
> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420
> )
> at
> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.ja
> va:65)
> at
> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73
> )
> at
> org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolE
> xecutor.java:1136)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
> Executor.java:635)
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr
> ead.java:61)
> at java.base/java.lang.Thread.run(Thread.java:833)
>
> I hope the stack shows the problem and helps to identify the problem.
> Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with
> http2 and is causing the issue.
>
> Thanks in advance!
> Thomas
>
> > -----Ursprüngliche Nachricht-----
> > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > <Th...@speed4trade.com.INVALID>
> > Gesendet: Mittwoch, 27. Juli 2022 20:52
> > An: Tomcat Users List <us...@tomcat.apache.org>
> > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> > connection with Firefox
> >
> > Oh... I also discovered an additional message in the wireshark dump.
> > Tomcat replied with a goaway packet with the text:
> > Connection [22], Stream [19], An error occurred during processing
> > that was fatal to the connection
> >
> > > -----Ursprüngliche Nachricht-----
> > > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > > <Th...@speed4trade.com.INVALID>
> > > Gesendet: Mittwoch, 27. Juli 2022 20:48
> > > An: Tomcat Users List <us...@tomcat.apache.org>
> > > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> > > closes connection with Firefox
> > >
> > > Hello Mark,
> > >
> > > I did some further investigations. I hope I don’t bother you with this
> topic.
> > >
> > > I was trying to narrow down the tomcat version where the problem
> > > started to appear.
> > > The problem with the interrupted connection started with 10.0.0-M8
> > > With Tomcat 10.0.0-M7 everything works fine.
> > >
> > > Comparing the sources, there are some (maybe relevant) changes in
> > > the
> > > org.apache.coyote.http2 package from M7 --> M8:
> > > - Http2AsynUpgradeHandler
> > > - Http2UpgradeHandler
> > > - Stream
> > > - StreamProcessor
> > >
> > > The observed problem was, that the browser (firefox) was sending a
> > > RST_Stream packet to close a single stream within the http2 protocol
> > > and tomcat was closing the whole connection instead of closing just
> > > that stream (wireshark dump would be available).
> > >
> > > In Stream.java a new method "doStreamCancel" was introduced (or an
> > > old method was renamed) with release M8.
> > > This looks related to the observed problem mentioned above.
> > >
> > > Does this information help to take a look again at this problem?
> > > If I should try something or can assist with testing, just let me know.
> > >
> > > Thanks!
> > > Thomas
> > >
> > >
> > >
> > >
> > > > -----Ursprüngliche Nachricht-----
> > > > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > > > <Th...@speed4trade.com.INVALID>
> > > > Gesendet: Dienstag, 5. Juli 2022 09:59
> > > > An: Tomcat Users List <us...@tomcat.apache.org>
> > > > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> > > > closes connection with Firefox
> > > >
> > > > Hallo Mark,
> > > >
> > > > > -----Ursprüngliche Nachricht-----
> > > > > Von: Mark Thomas <ma...@apache.org>
> > > > > Gesendet: Montag, 4. Juli 2022 19:37
> > > > > An: users@tomcat.apache.org
> > > > > Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
> > > > > closes connection with Firefox
> > > > >
> > > > > On 30/06/2022 07:40, Mark Thomas wrote:
> > > > >
> > > > > <snip/>
> > > > >
> > > > > > I think I'm going to need the sample app to investigate this.
> > > > >
> > > > > I have received the sample application and can recreate the issue.
> > > > >
> > > > > Going back to your original summary:
> > > > >
> > > > > <quote>
> > > > > 1) Main page was requested by Firefox from Tomcat (GET ...)
> > > > > 2) Tomcat sends the first compressed chunks of data to the
> > > > > browser
> > > > > 3) Firefox reads the first packages and notices, that additional
> > > > > resources are needed (CSS, JS ...)
> > > > > 4) While Tomcat is still sending the main page in chunks, the
> > > > > browser is already requesting additional resources on other
> > > > > channels
> > > > > 5) Firefox is sending a RST_STREAM and closes that last
> > > > > requested
> > > > > stream(s) (dunno why it does request first and then closes the
> > > > > channel)
> > > > > 6) Tomcat is sending a GoAway message to the browser
> > > > > 7) Tomcat stops also sending the main page (on a different
> > > > > channel) </quote>
> > > > >
> > > > > I tested with 10.0.x.
> > > > >
> > > > > I don't see the above sequence.
> > > > >
> > > > > I ran the test 4 times, closing the browser between each test
> > > > >
> > > > > When things go wrong it appears that FireFox is re-using the
> > > > > main page
> > > > > (ticket.jsp) from a cache.
> > > > >
> > > > > I see the additional resources being requested and then cancelled.
> > > > >
> > > > > I do not see any GOAWAY messages from Tomcat.
> > > > >
> > > > > I do see a single GOAWAY message from the browser to Tomcat
> when
> > > > > I close the browser window (as expected).
> > > > >
> > > > > I don't see anything going wrong on the Tomcat side.
> > > > >
> > > > > At the moment, this looks to me like an issue with Firefox
> > > > > rather than with Tomcat.
> > > > >
> > > > > If you can narrow the test case to something that shows Tomcat
> > > > > doing something wrong, then I'd be happy to look at this again.
> > > > >
> > > > > Mark
> > > > >
> > > > > ----------------------------------------------------------------
> > > > > --
> > > > > --
> > > > > -
> > > >
> > > > Thank you very much for taking a look at it!
> > > >
> > > > I could also see that the browser cache is used sometimes.
> > > > Sometimes the jsp is requested from the server, sometimes not.
> > > >
> > > > I did several tests again and the behaviour is not very
> > > > consistent, thus it's hard to get a handle on the problem.
> > > > I was also thinking about the possibility of a Firefox bug but
> > > > this wouldn’t explain that:
> > > > 1) It only happens with Tomcat 10.x and doesn’t show up with
> > > > Tomcat 9.x
> > > > 2) Users don’t report any problems with other internet websites
> > > > (using
> > > > Firefox)
> > > >
> > > > The GoAway seems to be sent from time to time by Tomcat, but not
> > > always.
> > > > I recorded one session which matches my last description:
> > > > https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
> > > > I set up another PC for testing, thus the IP addresses
> > > > (source/target) differ and can be interpreted more easily.
> > > > Maybe the last Capture was not readable without the keyfile, thus
> > > > I exported it differently and it should be readable now.
> > > >
> > > > a) Is the behaviour according to the linked network trace an
> > > > expected behaviour? (sending a GoAway after a rst_stream message)
> > > > b) Have you been able to reproduce the error with Tomcat 9.x?
> > > >
> > > > If you have any hints or suggestions, how I could narrow it down,
> > > > please drop a line.
> > > > I don’t have any big or great ideas at the moment.
> > > >
> > > > Thank you very much!
> > > > Thomas
> > > >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
I got a stack trace which also shows the involvement of the gzip filter. I set the loglevel for the http2-StreamProcessor to get the details.
The stack trace was written when the problem with FF occurred.
FF closed one single stream in http2 connection and tomcat seemed to have closed the whole TCP connection:
28-Jul-2022 22:16:40.939 FEIN [https-openssl-nio-443-exec-13] org.apache.coyote.http2.StreamProcessor.process Connection [0], Stream [23], An error occurred during processing that was fatal to the connection
java.lang.IllegalStateException: Connection [0], Stream [23], Unable to write to stream once it has been closed
at org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:880)
at org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStream.write(GzipOutputFilter.java:158)
at java.base/java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:171)
at org.apache.coyote.http11.filters.GzipOutputFilter.end(GzipOutputFilter.java:125)
at org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:71)
at org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:209)
at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:420)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:73)
at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:833)
I hope the stack shows the problem and helps to identify the problem.
Seems like the error handling has changed a bit with Tomcat 10.0.0 M8 with http2 and is causing the issue.
Thanks in advance!
Thomas
> -----Ursprüngliche Nachricht-----
> Von: Thomas Hoffmann (Speed4Trade GmbH)
> <Th...@speed4trade.com.INVALID>
> Gesendet: Mittwoch, 27. Juli 2022 20:52
> An: Tomcat Users List <us...@tomcat.apache.org>
> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> connection with Firefox
>
> Oh... I also discovered an additional message in the wireshark dump.
> Tomcat replied with a goaway packet with the text:
> Connection [22], Stream [19], An error occurred during processing that was
> fatal to the connection
>
> > -----Ursprüngliche Nachricht-----
> > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > <Th...@speed4trade.com.INVALID>
> > Gesendet: Mittwoch, 27. Juli 2022 20:48
> > An: Tomcat Users List <us...@tomcat.apache.org>
> > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> > connection with Firefox
> >
> > Hello Mark,
> >
> > I did some further investigations. I hope I don’t bother you with this topic.
> >
> > I was trying to narrow down the tomcat version where the problem
> > started to appear.
> > The problem with the interrupted connection started with 10.0.0-M8
> > With Tomcat 10.0.0-M7 everything works fine.
> >
> > Comparing the sources, there are some (maybe relevant) changes in the
> > org.apache.coyote.http2 package from M7 --> M8:
> > - Http2AsynUpgradeHandler
> > - Http2UpgradeHandler
> > - Stream
> > - StreamProcessor
> >
> > The observed problem was, that the browser (firefox) was sending a
> > RST_Stream packet to close a single stream within the http2 protocol
> > and tomcat was closing the whole connection instead of closing just
> > that stream (wireshark dump would be available).
> >
> > In Stream.java a new method "doStreamCancel" was introduced (or an old
> > method was renamed) with release M8.
> > This looks related to the observed problem mentioned above.
> >
> > Does this information help to take a look again at this problem?
> > If I should try something or can assist with testing, just let me know.
> >
> > Thanks!
> > Thomas
> >
> >
> >
> >
> > > -----Ursprüngliche Nachricht-----
> > > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > > <Th...@speed4trade.com.INVALID>
> > > Gesendet: Dienstag, 5. Juli 2022 09:59
> > > An: Tomcat Users List <us...@tomcat.apache.org>
> > > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes
> > > closes connection with Firefox
> > >
> > > Hallo Mark,
> > >
> > > > -----Ursprüngliche Nachricht-----
> > > > Von: Mark Thomas <ma...@apache.org>
> > > > Gesendet: Montag, 4. Juli 2022 19:37
> > > > An: users@tomcat.apache.org
> > > > Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
> > > > closes connection with Firefox
> > > >
> > > > On 30/06/2022 07:40, Mark Thomas wrote:
> > > >
> > > > <snip/>
> > > >
> > > > > I think I'm going to need the sample app to investigate this.
> > > >
> > > > I have received the sample application and can recreate the issue.
> > > >
> > > > Going back to your original summary:
> > > >
> > > > <quote>
> > > > 1) Main page was requested by Firefox from Tomcat (GET ...)
> > > > 2) Tomcat sends the first compressed chunks of data to the browser
> > > > 3) Firefox reads the first packages and notices, that additional
> > > > resources are needed (CSS, JS ...)
> > > > 4) While Tomcat is still sending the main page in chunks, the
> > > > browser is already requesting additional resources on other
> > > > channels
> > > > 5) Firefox is sending a RST_STREAM and closes that last requested
> > > > stream(s) (dunno why it does request first and then closes the
> > > > channel)
> > > > 6) Tomcat is sending a GoAway message to the browser
> > > > 7) Tomcat stops also sending the main page (on a different
> > > > channel) </quote>
> > > >
> > > > I tested with 10.0.x.
> > > >
> > > > I don't see the above sequence.
> > > >
> > > > I ran the test 4 times, closing the browser between each test
> > > >
> > > > When things go wrong it appears that FireFox is re-using the main
> > > > page
> > > > (ticket.jsp) from a cache.
> > > >
> > > > I see the additional resources being requested and then cancelled.
> > > >
> > > > I do not see any GOAWAY messages from Tomcat.
> > > >
> > > > I do see a single GOAWAY message from the browser to Tomcat when I
> > > > close the browser window (as expected).
> > > >
> > > > I don't see anything going wrong on the Tomcat side.
> > > >
> > > > At the moment, this looks to me like an issue with Firefox rather
> > > > than with Tomcat.
> > > >
> > > > If you can narrow the test case to something that shows Tomcat
> > > > doing something wrong, then I'd be happy to look at this again.
> > > >
> > > > Mark
> > > >
> > > > ------------------------------------------------------------------
> > > > --
> > > > -
> > >
> > > Thank you very much for taking a look at it!
> > >
> > > I could also see that the browser cache is used sometimes. Sometimes
> > > the jsp is requested from the server, sometimes not.
> > >
> > > I did several tests again and the behaviour is not very consistent,
> > > thus it's hard to get a handle on the problem.
> > > I was also thinking about the possibility of a Firefox bug but this
> > > wouldn’t explain that:
> > > 1) It only happens with Tomcat 10.x and doesn’t show up with Tomcat
> > > 9.x
> > > 2) Users don’t report any problems with other internet websites
> > > (using
> > > Firefox)
> > >
> > > The GoAway seems to be sent from time to time by Tomcat, but not
> > always.
> > > I recorded one session which matches my last description:
> > > https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
> > > I set up another PC for testing, thus the IP addresses
> > > (source/target) differ and can be interpreted more easily.
> > > Maybe the last Capture was not readable without the keyfile, thus I
> > > exported it differently and it should be readable now.
> > >
> > > a) Is the behaviour according to the linked network trace an
> > > expected behaviour? (sending a GoAway after a rst_stream message)
> > > b) Have you been able to reproduce the error with Tomcat 9.x?
> > >
> > > If you have any hints or suggestions, how I could narrow it down,
> > > please drop a line.
> > > I don’t have any big or great ideas at the moment.
> > >
> > > Thank you very much!
> > > Thomas
> > >
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Oh... I also discovered an additional message in the wireshark dump.
Tomcat replied with a goaway packet with the text:
Connection [22], Stream [19], An error occurred during processing that was fatal to the connection
> -----Ursprüngliche Nachricht-----
> Von: Thomas Hoffmann (Speed4Trade GmbH)
> <Th...@speed4trade.com.INVALID>
> Gesendet: Mittwoch, 27. Juli 2022 20:48
> An: Tomcat Users List <us...@tomcat.apache.org>
> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> connection with Firefox
>
> Hello Mark,
>
> I did some further investigations. I hope I don’t bother you with this topic.
>
> I was trying to narrow down the tomcat version where the problem started
> to appear.
> The problem with the interrupted connection started with 10.0.0-M8 With
> Tomcat 10.0.0-M7 everything works fine.
>
> Comparing the sources, there are some (maybe relevant) changes in the
> org.apache.coyote.http2 package from M7 --> M8:
> - Http2AsynUpgradeHandler
> - Http2UpgradeHandler
> - Stream
> - StreamProcessor
>
> The observed problem was, that the browser (firefox) was sending a
> RST_Stream packet to close a single stream within the http2 protocol and
> tomcat was closing the whole connection instead of closing just that stream
> (wireshark dump would be available).
>
> In Stream.java a new method "doStreamCancel" was introduced (or an old
> method was renamed) with release M8.
> This looks related to the observed problem mentioned above.
>
> Does this information help to take a look again at this problem?
> If I should try something or can assist with testing, just let me know.
>
> Thanks!
> Thomas
>
>
>
>
> > -----Ursprüngliche Nachricht-----
> > Von: Thomas Hoffmann (Speed4Trade GmbH)
> > <Th...@speed4trade.com.INVALID>
> > Gesendet: Dienstag, 5. Juli 2022 09:59
> > An: Tomcat Users List <us...@tomcat.apache.org>
> > Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> > connection with Firefox
> >
> > Hallo Mark,
> >
> > > -----Ursprüngliche Nachricht-----
> > > Von: Mark Thomas <ma...@apache.org>
> > > Gesendet: Montag, 4. Juli 2022 19:37
> > > An: users@tomcat.apache.org
> > > Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes
> > > closes connection with Firefox
> > >
> > > On 30/06/2022 07:40, Mark Thomas wrote:
> > >
> > > <snip/>
> > >
> > > > I think I'm going to need the sample app to investigate this.
> > >
> > > I have received the sample application and can recreate the issue.
> > >
> > > Going back to your original summary:
> > >
> > > <quote>
> > > 1) Main page was requested by Firefox from Tomcat (GET ...)
> > > 2) Tomcat sends the first compressed chunks of data to the browser
> > > 3) Firefox reads the first packages and notices, that additional
> > > resources are needed (CSS, JS ...)
> > > 4) While Tomcat is still sending the main page in chunks, the
> > > browser is already requesting additional resources on other channels
> > > 5) Firefox is sending a RST_STREAM and closes that last requested
> > > stream(s) (dunno why it does request first and then closes the
> > > channel)
> > > 6) Tomcat is sending a GoAway message to the browser
> > > 7) Tomcat stops also sending the main page (on a different channel)
> > > </quote>
> > >
> > > I tested with 10.0.x.
> > >
> > > I don't see the above sequence.
> > >
> > > I ran the test 4 times, closing the browser between each test
> > >
> > > When things go wrong it appears that FireFox is re-using the main
> > > page
> > > (ticket.jsp) from a cache.
> > >
> > > I see the additional resources being requested and then cancelled.
> > >
> > > I do not see any GOAWAY messages from Tomcat.
> > >
> > > I do see a single GOAWAY message from the browser to Tomcat when I
> > > close the browser window (as expected).
> > >
> > > I don't see anything going wrong on the Tomcat side.
> > >
> > > At the moment, this looks to me like an issue with Firefox rather
> > > than with Tomcat.
> > >
> > > If you can narrow the test case to something that shows Tomcat doing
> > > something wrong, then I'd be happy to look at this again.
> > >
> > > Mark
> > >
> > > --------------------------------------------------------------------
> > > -
> >
> > Thank you very much for taking a look at it!
> >
> > I could also see that the browser cache is used sometimes. Sometimes
> > the jsp is requested from the server, sometimes not.
> >
> > I did several tests again and the behaviour is not very consistent,
> > thus it's hard to get a handle on the problem.
> > I was also thinking about the possibility of a Firefox bug but this
> > wouldn’t explain that:
> > 1) It only happens with Tomcat 10.x and doesn’t show up with Tomcat
> > 9.x
> > 2) Users don’t report any problems with other internet websites (using
> > Firefox)
> >
> > The GoAway seems to be sent from time to time by Tomcat, but not
> always.
> > I recorded one session which matches my last description:
> > https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
> > I set up another PC for testing, thus the IP addresses (source/target)
> > differ and can be interpreted more easily.
> > Maybe the last Capture was not readable without the keyfile, thus I
> > exported it differently and it should be readable now.
> >
> > a) Is the behaviour according to the linked network trace an expected
> > behaviour? (sending a GoAway after a rst_stream message)
> > b) Have you been able to reproduce the error with Tomcat 9.x?
> >
> > If you have any hints or suggestions, how I could narrow it down,
> > please drop a line.
> > I don’t have any big or great ideas at the moment.
> >
> > Thank you very much!
> > Thomas
> >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> > For additional commands, e-mail: users-help@tomcat.apache.org
>
> B
> KKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKK
> KKKKKKKKKKCB [ X ܚX KK[XZ[
>
> \ \ ][ X ܚX P X ]
> \X K ܙ B ܈Y][ۘ[ [X[ K[XZ[
>
> \ \ Z[ X ]
> \X K ܙ B
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hello Mark,
I did some further investigations. I hope I don’t bother you with this topic.
I was trying to narrow down the tomcat version where the problem started to appear.
The problem with the interrupted connection started with 10.0.0-M8
With Tomcat 10.0.0-M7 everything works fine.
Comparing the sources, there are some (maybe relevant) changes in the org.apache.coyote.http2 package from M7 --> M8:
- Http2AsynUpgradeHandler
- Http2UpgradeHandler
- Stream
- StreamProcessor
The observed problem was, that the browser (firefox) was sending a RST_Stream packet to close a single stream within the http2 protocol
and tomcat was closing the whole connection instead of closing just that stream (wireshark dump would be available).
In Stream.java a new method "doStreamCancel" was introduced (or an old method was renamed) with release M8.
This looks related to the observed problem mentioned above.
Does this information help to take a look again at this problem?
If I should try something or can assist with testing, just let me know.
Thanks!
Thomas
> -----Ursprüngliche Nachricht-----
> Von: Thomas Hoffmann (Speed4Trade GmbH)
> <Th...@speed4trade.com.INVALID>
> Gesendet: Dienstag, 5. Juli 2022 09:59
> An: Tomcat Users List <us...@tomcat.apache.org>
> Betreff: AW: AW: Tomcat 10 with Http2 and compression sometimes closes
> connection with Firefox
>
> Hallo Mark,
>
> > -----Ursprüngliche Nachricht-----
> > Von: Mark Thomas <ma...@apache.org>
> > Gesendet: Montag, 4. Juli 2022 19:37
> > An: users@tomcat.apache.org
> > Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes closes
> > connection with Firefox
> >
> > On 30/06/2022 07:40, Mark Thomas wrote:
> >
> > <snip/>
> >
> > > I think I'm going to need the sample app to investigate this.
> >
> > I have received the sample application and can recreate the issue.
> >
> > Going back to your original summary:
> >
> > <quote>
> > 1) Main page was requested by Firefox from Tomcat (GET ...)
> > 2) Tomcat sends the first compressed chunks of data to the browser
> > 3) Firefox reads the first packages and notices, that additional
> > resources are needed (CSS, JS ...)
> > 4) While Tomcat is still sending the main page in chunks, the browser
> > is already requesting additional resources on other channels
> > 5) Firefox is sending a RST_STREAM and closes that last requested
> > stream(s) (dunno why it does request first and then closes the
> > channel)
> > 6) Tomcat is sending a GoAway message to the browser
> > 7) Tomcat stops also sending the main page (on a different channel)
> > </quote>
> >
> > I tested with 10.0.x.
> >
> > I don't see the above sequence.
> >
> > I ran the test 4 times, closing the browser between each test
> >
> > When things go wrong it appears that FireFox is re-using the main page
> > (ticket.jsp) from a cache.
> >
> > I see the additional resources being requested and then cancelled.
> >
> > I do not see any GOAWAY messages from Tomcat.
> >
> > I do see a single GOAWAY message from the browser to Tomcat when I
> > close the browser window (as expected).
> >
> > I don't see anything going wrong on the Tomcat side.
> >
> > At the moment, this looks to me like an issue with Firefox rather than
> > with Tomcat.
> >
> > If you can narrow the test case to something that shows Tomcat doing
> > something wrong, then I'd be happy to look at this again.
> >
> > Mark
> >
> > ---------------------------------------------------------------------
>
> Thank you very much for taking a look at it!
>
> I could also see that the browser cache is used sometimes. Sometimes the
> jsp is requested from the server, sometimes not.
>
> I did several tests again and the behaviour is not very consistent, thus it's
> hard to get a handle on the problem.
> I was also thinking about the possibility of a Firefox bug but this wouldn’t
> explain that:
> 1) It only happens with Tomcat 10.x and doesn’t show up with Tomcat 9.x
> 2) Users don’t report any problems with other internet websites (using
> Firefox)
>
> The GoAway seems to be sent from time to time by Tomcat, but not always.
> I recorded one session which matches my last description:
> https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
> I set up another PC for testing, thus the IP addresses (source/target) differ
> and can be interpreted more easily.
> Maybe the last Capture was not readable without the keyfile, thus I
> exported it differently and it should be readable now.
>
> a) Is the behaviour according to the linked network trace an expected
> behaviour? (sending a GoAway after a rst_stream message)
> b) Have you been able to reproduce the error with Tomcat 9.x?
>
> If you have any hints or suggestions, how I could narrow it down, please drop
> a line.
> I don’t have any big or great ideas at the moment.
>
> Thank you very much!
> Thomas
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
AW: AW: Tomcat 10 with Http2 and compression sometimes closes connection with Firefox
Posted by "Thomas Hoffmann (Speed4Trade GmbH)" <Th...@speed4trade.com.INVALID>.
Hallo Mark,
> -----Ursprüngliche Nachricht-----
> Von: Mark Thomas <ma...@apache.org>
> Gesendet: Montag, 4. Juli 2022 19:37
> An: users@tomcat.apache.org
> Betreff: Re: AW: Tomcat 10 with Http2 and compression sometimes closes
> connection with Firefox
>
> On 30/06/2022 07:40, Mark Thomas wrote:
>
> <snip/>
>
> > I think I'm going to need the sample app to investigate this.
>
> I have received the sample application and can recreate the issue.
>
> Going back to your original summary:
>
> <quote>
> 1) Main page was requested by Firefox from Tomcat (GET ...)
> 2) Tomcat sends the first compressed chunks of data to the browser
> 3) Firefox reads the first packages and notices, that additional resources are
> needed (CSS, JS ...)
> 4) While Tomcat is still sending the main page in chunks, the browser is
> already requesting additional resources on other channels
> 5) Firefox is sending a RST_STREAM and closes that last requested
> stream(s) (dunno why it does request first and then closes the channel)
> 6) Tomcat is sending a GoAway message to the browser
> 7) Tomcat stops also sending the main page (on a different channel)
> </quote>
>
> I tested with 10.0.x.
>
> I don't see the above sequence.
>
> I ran the test 4 times, closing the browser between each test
>
> When things go wrong it appears that FireFox is re-using the main page
> (ticket.jsp) from a cache.
>
> I see the additional resources being requested and then cancelled.
>
> I do not see any GOAWAY messages from Tomcat.
>
> I do see a single GOAWAY message from the browser to Tomcat when I close
> the browser window (as expected).
>
> I don't see anything going wrong on the Tomcat side.
>
> At the moment, this looks to me like an issue with Firefox rather than with
> Tomcat.
>
> If you can narrow the test case to something that shows Tomcat doing
> something wrong, then I'd be happy to look at this again.
>
> Mark
>
> ---------------------------------------------------------------------
Thank you very much for taking a look at it!
I could also see that the browser cache is used sometimes. Sometimes the jsp is requested from the server, sometimes not.
I did several tests again and the behaviour is not very consistent, thus it's hard to get a handle on the problem.
I was also thinking about the possibility of a Firefox bug but this wouldn’t explain that:
1) It only happens with Tomcat 10.x and doesn’t show up with Tomcat 9.x
2) Users don’t report any problems with other internet websites (using Firefox)
The GoAway seems to be sent from time to time by Tomcat, but not always.
I recorded one session which matches my last description: https://privfile.com/download.php?fid=62c3ec1170199-MTM2OTM=
I set up another PC for testing, thus the IP addresses (source/target) differ and can be interpreted more easily.
Maybe the last Capture was not readable without the keyfile, thus I exported it differently and it should be readable now.
a) Is the behaviour according to the linked network trace an expected behaviour? (sending a GoAway after a rst_stream message)
b) Have you been able to reproduce the error with Tomcat 9.x?
If you have any hints or suggestions, how I could narrow it down, please drop a line.
I don’t have any big or great ideas at the moment.
Thank you very much!
Thomas
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org