> > > > > > Hello,
> > > > > >
> > > > > > Since upgrading from Tomcat 9.0.56 to Tomcat 10.0.16, the
> > > > > > localhost-logfile
> > > > > is filling up with stacks of the form:
> > > > > >
> > > > > > 07-Mar-2022 07:24:01.780 SCHWERWIEGEND
> > > > > > [https-openssl-nio-443-exec-
> > > > > 21] org.apache.catalina.core.ApplicationDispatcher.invoke
> > > > > Servlet.service() for servlet [jsp] threw exception
> > > > > > java.lang.IllegalStateException: Connection [66],
> > > > > > Stream [113], Unable
> > > > > to write to stream once it has been closed
> > > > > > at
> > > > >
> > >
> >
> org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:
> > > > > 843)
> > > > > > at
> > > > > org.apache.coyote.http11.filters.GzipOutputFilter$FakeOutputStre
> > > > > am
> > > > > .w
> > > > > rite(
> > > > > GzipOutputFilter.java:159)
> > > > > > at
> > > > >
> > >
> >
> java.base/java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.
> > > > > java:252)
> > > > > > at
> > > > > java.base/java.util.zip.DeflaterOutputStream.write(DeflaterOutpu
> > > > > tS
> > > > > tr
> > > > > eam.ja
> > > > > va:210)
> > > > > > at
> > > > > java.base/java.util.zip.GZIPOutputStream.write(GZIPOutputStream.
> > > > > ja
> > > > > va
> > > > > :148
> > > > > )
> > > > > > at
> > > > >
> > >
> >
> org.apache.coyote.http11.filters.GzipOutputFilter.doWrite(GzipOutputFilter.
> > > > > java:69)
> > > > > > at
> > > > >
> > >
> org.apache.coyote.http2.Http2OutputBuffer.doWrite(Http2OutputBuffer.
> > > > > jav
> > > > > a:59)
> > > > > > at
> org.apache.coyote.Response.doWrite(Response.java:625)
> > > > > > at
> > > > > org.apache.catalina.connector.OutputBuffer.realWriteBytes(Output
> > > > > Bu
> > > > > ff
> > > > > er.ja
> > > > > va:340)
> > > > > > at
> > > > > org.apache.catalina.connector.OutputBuffer.flushByteBuffer(Outpu
> > > > > tB
> > > > > uf
> > > > > fer.j
> > > > > ava:783)
> > > > > > at
> > > > > org.apache.catalina.connector.OutputBuffer.realWriteChars(Output
> > > > > Bu
> > > > > ff
> > > > > er.ja
> > > > > va:453)
> > > > > > at
> > > > > org.apache.catalina.connector.OutputBuffer.flushCharBuffer(Outpu
> > > > > tB
> > > > > uf
> > > > > fer.j
> > > > > ava:788)
> > > > > > at
> > > > >
> > org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:
> > > > > 727)
> > > > > > at
> > > > > org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.ja
> > > > > va
> > > > > :5
> > > > > 05)
> > > > > > at
> > > > > org.apache.catalina.connector.CoyoteWriter.write(CoyoteWriter.ja
> > > > > va
> > > > > :1
> > > > > 48)
> > > > > > at
> > > > >
> > >
> >
> org.apache.catalina.filters.ExpiresFilter$XPrintWriter.write(ExpiresFilter.java:
> > > > > 850)
> > > > > > at
> > > > > org.apache.jasper.runtime.JspWriterImpl.write(JspWriterImpl.java
> > > > > :2
> > > > > 75
> > > > > )
> > > > > > at
> > > > > > java.base/java.io.PrintWriter.write(PrintWriter.java:506)
> > > > > > at
> > > > > org.apache.jasper.runtime.JspWriterImpl.write(JspWriterImpl.java
> > > > > :2
> > > > > 75
> > > > > )
> > > > > > at
> > > > > > java.base/java.io.PrintWriter.write(PrintWriter.java:506)
> > > > > > at
> > > > > org.apache.jasper.runtime.JspWriterImpl.flushBuffer(JspWriterImpl.
> > > > > ja
> > > > > va:112
> > > > > )
> > > > > > at
> > > > > org.apache.jasper.runtime.JspWriterImpl.flush(JspWriterImpl.java
> > > > > :1
> > > > > 60
> > > > > )
> > > > > > at
> > > > > org.apache.jsp.WEB_002dINF.jsp.businessrelations.ticket_005frela
> > > > > ti
> > > > > on
> > > > > s_inc_
> > > > > jsp._jspService(ticket_005frelations_inc_jsp.java:702)
> > > > > > ...
> > > > > >
> > > > > > The jsp-file varies between the stacktraces, so it is not
> > > > > > related to a certain
> > > > > jsp-File.
> > > > > > The stream.java looks like (which didn’t change from Tomcat 9 to
> 10):
> > > > > > @Override
> > > > > > public final synchronized int doWrite(ByteBuffer
> > > > > > chunk) throws
> > > > > IOException {
> > > > > > if (closed) {
> > > > > > throw new IllegalStateException(
> > > > > > sm.getString("stream.closed",
> > > > > > getConnectionId(), getIdAsString()));
> > > > >
> > > > > I wonder why it throws an ISE here, instead of a proper
> > > > > IOException as declared by this method.
> > > > > (It looks like a bug, but I have not investigated the history of
> > > > > this code yet.)
> > > > >
> > > > > There is nothing suspicious in the stacktrace. An unusual bit of
> > > > > configuration here is having enabled a GzipOutputFilter.
> > > > >
> > > > > Best regards,
> > > > > Konstantin Kolinko
> > > >
> > > > Good observation about the GZip-Filter!
> > > > We are using compression="force" in our connector.
> > > > I modified some http2 settings (raised some limits) and set
> > > compression="off" ... up to now, the error disappeared.
> > > > As I modified several settings, I will carefully revert the
> > > > changes step by
> > > step to figure out which connector parameter is causing this error.
> > > > Maybe the GZip-Filter doesn’t work well with the http2 protocol in
> > tomcat.
> > > > I will investigate and post the results.
> > >
> > > Mark has already changed that IllegalStateException to an
> > > IOException, and that is included into 10.0.18 that has already
> > > been tagged and is currently being voted for an official release.
> > >
> > > You may take part in the testing. See VOTE thread on the dev mailing
> > > list for links.
> > >
> > > Best regards,
> > > Konstantin Kolinko
> >
> > Hm... some users reported blank pages from time to time which seem to
> > correlate with the error in the logfile. After hitting F5 the page appeared.
> > So I am not sure if changing the Exception-Type finally solves the issue.
>
> Hello,
> short update on that issue.
> I could track down the problem to the combination http2 and
> compression="force".
> In this combination, the errors occur. When using compression="no", the
> error is gone.
> With compression="force", users are reporting issues with pages, not fully
> getting loaded. Only half of the page is sometimes shown.
> Pressing F5 and the page shows up again.
> It seems that http2 and compression causes some issues so that browser or
> server is closing the connection.
>
> I could further test, whether compression="on" has the same issue.
> Another option would be to test with tomcat 10.0.18 but as only the
> exception type changed, I have some doubts whether it fixes the root cause.
> Setting logging to finest would also be an option. In this case it would be
> helpful to be able to reload the logging.properties during runtime or changing
> the loglevel during runtime. Unfortunately I couldn’t get it to work. Changing
> loglevel during runtime doesn’t show any effect, even if I change the
> context-classloader before calling
> LogFactory.getLog("org.apache.coyote.http2")
>
> Any thoughts how to track down the issue or how I can provide further
> information to help the tomcat team to find the issue?
> The issue didn’t show up in 9.0.56 but after upgrading to 10.0.16
>
> Thanks! Thomas
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
Hello Konstantin and Mark,
I could further track down the issue.
The stracktrace is not written any more to the log with Tomcat 9.0.18 but the
client problem still persist.
I am also able to reproduce the problem with few tries now.
Partly received web pages on client side occur in the following situation:
- Connector-Compression is "on" or "force"
- Browser is using http2 protocol
- Happens since upgrade from Tomcat 9.0.56 to 10.0.16 (didn’t occur with Tomcat
9)
- Occurs in Firefox when opening a link by clicking the middle mouse button
Setting the loglevel to FINE I got the following stacks:
https://store1.gofile.io/download/3bc103b0-ecc5-42ac-bedb-da53bcdbb6f0/http2.log.txt
(quite long, so I uploaded it to a separate site).
Is there any helpful information contained?
Anything else I can do to help investigating the issue?
Thanks in advance! Thomas
