https://bz.apache.org/bugzilla/show_bug.cgi?id=69471

            Bug ID: 69471
           Summary: CloseNowException logged in ApplicationDispatcher
           Product: Tomcat 10
           Version: 10.1.33
          Hardware: PC
            Status: NEW
          Severity: minor
          Priority: P2
         Component: Catalina
          Assignee: dev@tomcat.apache.org
          Reporter: andreas.bergan...@gmail.com
  Target Milestone: ------

I'm using a connector with HTTP/2 enabled in Tomcat 10.1.33 and sometimes we
receive a RST_STREAM from the client before we have written the response fully.
That will cause an error to be logged by the ApplicationDispatcher, but isn't
this a valid scenario that shouldn't be logged as an error?

When the HTTP/2 stream receives a RST_STREAM (indicating that the client is no
longer interested in the response) then the stream is immediately closed. But
since the request is still going on, writing to that closed stream will cause
org.apache.coyote.http2.Stream to throw a CloseNowException with cause
StreamException: "Connection [e4cc], Stream [129], This stream is in state
[CLOSED_RST_RX] and is not writable"

The ApplicationDispatcher.invoke(...) will then log this error since
CloseNowException extends IOException.

My question is, should this be logged as an error or should it instead be
handle similar to a BadRequestException and ClientAbortException and not be
logged?

Can this in ApplicationDispatcher.invoke(...):

} catch (BadRequestException e) {
        ioException = e;
} catch (IOException e) {
       
wrapper.getLogger().error(sm.getString("applicationDispatcher.serviceException",
wrapper.getName()), e);
        ioException = e;
}

be changed to this:

} catch (BadRequestException e) {
        ioException = e;
} catch (CloseNowException e) {
        ioException = e;
} catch (IOException e) {
       
wrapper.getLogger().error(sm.getString("applicationDispatcher.serviceException",
wrapper.getName()), e);
        ioException = e;
}

Or will that cause any other problems? Is there other cases where a
CloseNowException should be logged in ApplicationDispatcher?

Also, I can see that in StandardWrapperValve that both BadRequestException and
CloseNowException are logged at debug level, while IOException on error level.
So making this change in ApplicationDispatcher would make it more consistent
with how StandardWrapperValve handles CloseNowException.

Any thoughts?

This is the full stacktrace logged:

Servlet.service() for servlet [default] threw exception:
org.apache.coyote.CloseNowException: Connection [e4cc], Stream [129], This
stream is in state [CLOSED_RST_RX] and is not writable
        at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:304)
        at
org.apache.coyote.http2.Http2UpgradeHandler.reserveWindowSize(Http2UpgradeHandler.java:946)
        at
org.apache.coyote.http2.Stream$StreamOutputBuffer.flush(Stream.java:1120)
        at
org.apache.coyote.http2.Stream$StreamOutputBuffer.doWrite(Stream.java:1035)
        at
org.apache.coyote.http2.Http2OutputBuffer.doWrite(Http2OutputBuffer.java:57)
        at org.apache.coyote.Response.doWrite(Response.java:633)
        at
org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:329)
        at
org.apache.catalina.connector.OutputBuffer.appendByteArray(OutputBuffer.java:746)
        at
org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:667)
        at
org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:376)
        at
org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:354)
        at
org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:103)
        at
org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:95)
        at
org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:1076)
        at
org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:508)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564)
        at
org.apache.catalina.servlets.DefaultServlet.service(DefaultServlet.java:498)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:632)
        at
org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:408)
        at
org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:303)
        at
org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:267)
        at
org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler.handleRequest(DefaultServletHttpRequestHandler.java:130)
        at
org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle(HttpRequestHandlerAdapter.java:52)
        at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
        at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
        at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
        at
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564)
        at
org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter(HttpHeaderSecurityFilter.java:129)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
        at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
        at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
        at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:598)
        at
org.apache.catalina.valves.rewrite.RewriteValve.invoke(RewriteValve.java:543)
        at org.apache.catalina.valves.SSLValve.invoke(SSLValve.java:193)
        at
org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:731)
        at
org.apache.catalina.valves.RequestFilterValve.process(RequestFilterValve.java:355)
        at
org.apache.catalina.valves.RemoteAddrValve.invoke(RemoteAddrValve.java:54)
        at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
        at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
        at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at
ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:267)
        at org.apache.catalina.valves.SSLValve.invoke(SSLValve.java:193)
        at
org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:731)
        at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
        at
org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:469)
        at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
        at
org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:101)
        at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
        at
org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190)
        at
org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
        at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63)
        at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: org.apache.coyote.http2.StreamException: Connection [e4cc], Stream
[129], This stream is in state [CLOSED_RST_RX] and is not writable
        at org.apache.coyote.http2.Stream.doStreamCancel(Stream.java:296)
        ... 96 common frames omitted

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to