You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by bu...@apache.org on 2021/07/21 12:02:41 UTC

[Bug 65460] New: http2 request hang with tomcat 9.0.50`s overhead protection

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

            Bug ID: 65460
           Summary: http2 request hang with tomcat 9.0.50`s overhead
                    protection
           Product: Tomcat 9
           Version: 9.0.50
          Hardware: PC
                OS: Mac OS X 10.1
            Status: NEW
          Severity: major
          Priority: P2
         Component: Connectors
          Assignee: dev@tomcat.apache.org
          Reporter: dpy1123@126.com
  Target Milestone: -----

Question:
When we are using http2 and upgrading tomcat`s version from 9.0.45 to 9.0.50.
We find when server first startup evernthing goes fine, but after a while we
see may request timeout from client side.

By seeing the pinpoint trace, we find request is blocking at
StandardHostValve#invoke. Then caller get timeout, and disconnect. Then some
how the server side finish its blocking and try to read/write some to the
socket, then got exception like:
"IOException: stream reset"
or
"CloseNowException: This stream is not writeable"

And in changelog, since 9.0.49 we see some new changes in http2
overheadprotect, we think maybe these changes cause the problem. So we did some
tests blow:
1. http1 + tomcat9.0.50  fine
2. http2 + tomcat9.0.50  hang
3. http2 + tomcat9.0.45  fine
4. http2 + tomcat9.0.50 + disable overheadprotect  fine

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #12 from dpy1123 <dp...@126.com> ---
Created attachment 37967
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=37967&action=edit
thread dump when hang

add thread dump

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


[Bug 65460] http2 request hang on request read

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #15 from dpy1123 <dp...@126.com> ---
c(In reply to Mark Thomas from comment #14)
> Found it. There is a regression in the previous release.
> 
> If using async IO (available and default in 9.x and 10.x) small updates to
> the connection flow control window were dropped. The window slowly reduced
> in size until no more data could be read.
> 
> If not using async IO, small updates to the connection flow control window
> are written but not flushed so at worst, you'll see a small delay.
> 
> Setting overheadWindowUpdateThreshold="0" avoids the issue with or without
> async IO.
> 
> Fixed in:
> - 10.1.x for 10.1.0-M3 onwards
> - 10.0.x for 10.0.9 onwards
> - 9.0.x for 9.0.51 onwards
> - 8.5.x for 8.5.70 onwards

cool~ looking forward to next release.
Thx for helping~

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |NEEDINFO

--- Comment #4 from Mark Thomas <ma...@apache.org> ---
HTTP/2 is not enabled by default so you can't possibly be using default
settings. I specifically asked for the full Connector configurations for that
reason. Please provide the complete Connector configuration please for both the
hanging and working cases as requested.

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


[Bug 65460] http2 request hang on request read

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|http2 request hang with     |http2 request hang on
                   |tomcat 9.0.50's overhead    |request read
                   |protection                  |

--- Comment #13 from Mark Thomas <ma...@apache.org> ---
I'm as sure as I can be this isn't overhead protection related.

The HTTP/2 streams are blocked, waiting to receive data. If the overhead
protection had been triggered, these streams would have been closed. The
exceptions in the logs are also consistent with request reads timing out.

What isn't yet clear is the root cause. Possibilities are:
1. The client isn't sending data. Unlikely given the issue started after the
move from 9.0.45 to 9.0.50.
2. The data is being received but the stream isn't being notified. Unlikely as
there have been no changes in this specific area.
3. Window updates are not being sent correctly. Seems the most likely candidate
at this point as there are changes for this in 9.0.49.

I was about to suggest a couple of things to try to collect more data. As part
of that I was checking exactly what debug logging is provided for Window
updates and I managed to recreate the issue.

I'm investigating now but setting overheadWindowUpdateThreshold="0" seems to
work around the issue.

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #9 from dpy1123 <dp...@126.com> ---
Created attachment 37965
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=37965&action=edit
some wired cases

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

dpy1123 <dp...@126.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
          Component|Connectors                  |Catalina

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

dpy1123 <dp...@126.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |NEW

--- Comment #3 from dpy1123 <dp...@126.com> ---
all the test cases except case.4 are using the default settings. 
case.4 just add follow settings to disable overhead protection:
overheadCountFactor="0"
overheadDataThreshold="0"
overheadWindowUpdateThreshold="0"

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


[Bug 65460] http2 request hang on request read

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #14 from Mark Thomas <ma...@apache.org> ---
Found it. There is a regression in the previous release.

If using async IO (available and default in 9.x and 10.x) small updates to the
connection flow control window were dropped. The window slowly reduced in size
until no more data could be read.

If not using async IO, small updates to the connection flow control window are
written but not flushed so at worst, you'll see a small delay.

Setting overheadWindowUpdateThreshold="0" avoids the issue with or without
async IO.

Fixed in:
- 10.1.x for 10.1.0-M3 onwards
- 10.0.x for 10.0.9 onwards
- 9.0.x for 9.0.51 onwards
- 8.5.x for 8.5.70 onwards

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #11 from dpy1123 <dp...@126.com> ---
Created attachment 37966
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=37966&action=edit
txt version

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

dpy1123 <dp...@126.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |NEW

--- Comment #10 from dpy1123 <dp...@126.com> ---
add a pdf version through attachment, pls take a look.

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

dpy1123 <dp...@126.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |NEW

--- Comment #5 from dpy1123 <dp...@126.com> ---
we are using embed tomcat together with spring boot.Here`s what we added:
server.http2.enable=true

use 'TomcatServletWebServerFactory' to customize connection by adding:
http2Protocol.setMaxConcurrentStreams(100);
http2Protocol.setMaxConcurrentStreamExecution(20);
http2Protocol.setKeepAliveTimeout(60_000);
connector.addUpgradeProtocol(http2Protocol);

and with case.4 additional settings are:
http2Protocol.setOverheadCountFactor(0);
http2Protocol.setOverheadDataThreshold(0);
http2Protocol.setOverheadWindowUpdateThreshold(0);

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|http2 request hang with     |http2 request hang with
                   |tomcat 9.0.50`s overhead    |tomcat 9.0.50's overhead
                   |protection                  |protection

--- Comment #8 from Mark Thomas <ma...@apache.org> ---
That reference requires registration/authentication. Please ensure any links
you provide are public.

A thread dump when the hang occurs would be helpful.

Enabling HTTP/2 debug logging may also be informative (see
$CATALINA_BASE/logging.properties)

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #1 from dpy1123 <dp...@126.com> ---
A stack trace when blocking happens:

void java.lang.Object.wait(long) 272 97.1 %
int
org.apache.coyote.http2.Stream$StreamInputBuffer.doRead(ApplicationBufferHandler)
272 97.1 %
int org.apache.coyote.Request.doRead(ApplicationBufferHandler) 272 97.1 %
int org.apache.catalina.connector.InputBuffer.realReadBytes() 272 97.1 %
boolean org.apache.catalina.connector.InputBuffer.checkByteBufferEof() 272 97.1
%
int org.apache.catalina.connector.InputBuffer.read(byte[], int, int) 272 97.1 %
int org.apache.catalina.connector.CoyoteInputStream.read(byte[], int, int) 272
97.1 %
int org.apache.catalina.connector.CoyoteInputStream.read(byte[]) 272 97.1 %
long org.apache.commons.io.IOUtils.copyLarge(InputStream, OutputStream, byte[])
272 97.1 %
long org.apache.commons.io.IOUtils.copy(InputStream, OutputStream, int) 272
97.1 %
long org.apache.commons.io.IOUtils.copyLarge(InputStream, OutputStream) 272
97.1 %
int org.apache.commons.io.IOUtils.copy(InputStream, OutputStream) 272 97.1 %
byte[] org.apache.commons.io.IOUtils.toByteArray(InputStream) 272 97.1 %
void
com.OURCODEBASE.platform.openfeign.body.CustomBodyServletRequestWrapper.<init>(HttpServletRequest)
272 97.1 %
void
com.OURCODEBASE.platform.openfeign.body.RequestBodyCacheFilter.doFilterInternal(HttpServletRequest,
HttpServletResponse, FilterChain) 272 97.1 %
void
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest,
ServletResponse, FilterChain) 272 97.1 %
void
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest,
ServletResponse) 272 97.1 %
void org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest,
ServletResponse) 272 97.1 %
void
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(HttpServletRequest,
HttpServletResponse, FilterChain) 272 97.1 %
void
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest,
ServletResponse, FilterChain) 272 97.1 %
void
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest,
ServletResponse) 272 97.1 %
void org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest,
ServletResponse) 272 97.1 %
void
com.OURCODEBASE.platform.monitor.logging.tracing.TracingOncePerRequestFilter.doFilterInternal(HttpServletRequest,
HttpServletResponse, FilterChain) 272 97.1 %
void
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest,
ServletResponse, FilterChain) 272 97.1 %
void
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest,
ServletResponse) 272 97.1 %
void org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest,
ServletResponse) 272 97.1 %
void org.apache.catalina.core.StandardWrapperValve.invoke(Request, Response)
272 97.1 %
void org.apache.catalina.core.StandardContextValve.invoke(Request, Response)
272 97.1 %
void org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request,
Response) 272 97.1 %
void org.apache.catalina.core.StandardHostValve.invoke(Request, Response) 272
97.1 %
void org.apache.catalina.valves.ErrorReportValve.invoke(Request, Response) 272
97.1 %
void org.apache.catalina.core.StandardEngineValve.invoke(Request, Response) 272
97.1 %
void org.apache.catalina.connector.CoyoteAdapter.service(Request, Response) 272
97.1 %
AbstractEndpoint$Handler$SocketState
org.apache.coyote.http2.StreamProcessor.service(SocketWrapperBase) 272 97.1 %
AbstractEndpoint$Handler$SocketState
org.apache.coyote.AbstractProcessorLight.process(SocketWrapperBase,
SocketEvent) 272 97.1 %
void org.apache.coyote.http2.StreamProcessor.process(SocketEvent) 272 97.1 %
void org.apache.coyote.http2.StreamRunnable.run() 272 97.1 %
void
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
272 97.1 %
void java.util.concurrent.ThreadPoolExecutor$Worker.run() 272 97.1 %
void org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run() 272 97.1
%
void java.lang.Thread.run() 272 97.1 %

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #6 from dpy1123 <dp...@126.com> ---
we run several more times with case.2 and find:
when overhead count disconut to around -10640 to -10660, next request will hang
till timeout and any requests after this will also hang till timeout. 


we see these in log:
Connection [35], Stream [0], Frame type [DATA] resulted in new overhead count
of [-10,680]
Connection [35], Stream [0], Frame type [HEADERS] resulted in new overhead
count of [-10,660]
Connection [35], Stream [0], Frame type [HEADERS] resulted in new overhead
count of [-10,620]
Connection [35], Stream [0], Frame type [DATA] resulted in new overhead count
of [-10,640]
Connection [35], Stream [0], Frame type [HEADERS] resulted in new overhead
count of [-10,580]

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |NEEDINFO

--- Comment #2 from Mark Thomas <ma...@apache.org> ---
Complete Connector configuration please for both the hanging and working cases.

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


[Bug 65460] http2 request hang with tomcat 9.0.50`s overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

--- Comment #7 from dpy1123 <dp...@126.com> ---
sorry I think the overhead cout is fine, we try another api and got a different
overhead count when issue happens.

besides, we find some wired cases, pls see the reference:
https://www.notion.so/dpy1123/tomcat9-0-50-hang-01a1f5527c944f919a700fc39fd9d58d

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


[Bug 65460] http2 request hang with tomcat 9.0.50's overhead protection

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=65460

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |NEEDINFO

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