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)
>> <thomas.hoffm...@speed4trade.com.INVALID>
>> Gesendet: Donnerstag, 28. Juli 2022 22:25
>> An: Tomcat Users List <users@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)
>>> <thomas.hoffm...@speed4trade.com.INVALID>
>>> Gesendet: Mittwoch, 27. Juli 2022 20:52
>>> An: Tomcat Users List <users@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)
>>>> <thomas.hoffm...@speed4trade.com.INVALID>
>>>> Gesendet: Mittwoch, 27. Juli 2022 20:48
>>>> An: Tomcat Users List <users@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)
>>>>> <thomas.hoffm...@speed4trade.com.INVALID>
>>>>> Gesendet: Dienstag, 5. Juli 2022 09:59
>>>>> An: Tomcat Users List <users@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-unsubscr...@tomcat.apache.org
>> For additional commands, e-mail: users-h...@tomcat.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
