Re: HTTP2 : WINDOW_UPDATE not sent on stream level
On 13/01/2022 21:45, Doug Whitfield wrote: Hi Mark, In the newly opened bug report about this (https://bz.apache.org/bugzilla/show_bug.cgi?id=65773), you noted that logging at level FINE would show what is happening. What exactly are we looking at when it says it “Swallowed [0] bytes”? I can get more data, but at this point, I just want to understand the log sample: Time: 2022-01-12 03:44:42.895, Level: FINE, Logger: org.apache.coyote.http2.Http2Parser org.apache.coyote.http2.Http2Parser swallow - Connection [54], Stream [2076417], Swallowed [0] bytes It means that for some reason Tomcat needed to swallow some or all of the payload for a frame and in this instance the payload was empty. Possible reasons for swallowing (ignoring) the payload include: - an error exception has occurred and the payload won't be processed - padding flag has been set (frames can have zero length padding) - the frame is of an unknown type If you look further back in the debug trace for that stream the previous messages should identify which this is. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: HTTP2 : WINDOW_UPDATE not sent on stream level
Hi Mark, In the newly opened bug report about this (https://bz.apache.org/bugzilla/show_bug.cgi?id=65773), you noted that logging at level FINE would show what is happening. What exactly are we looking at when it says it “Swallowed [0] bytes”? I can get more data, but at this point, I just want to understand the log sample: Time: 2022-01-12 03:44:42.895, Level: FINE, Logger: org.apache.coyote.http2.Http2Parser org.apache.coyote.http2.Http2Parser swallow - Connection [54], Stream [2076417], Swallowed [0] bytes Best Regards, -- Doug Whitfield | Enterprise Architect, OpenLogic<https://www.openlogic.com/?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> Perforce Software<http://www.perforce.com/?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> Visit us on: LinkedIn<https://www.linkedin.com/company/perforce?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> | Twitter<https://twitter.com/perforce?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> | Facebook<https://www.facebook.com/perforce/?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> | YouTube<https://www.youtube.com/user/perforcesoftware?utm_leadsource=email-signature_source=outlook-direct-email_medium=email_campaign=2019-common_content=email-signature-link> From: Mark Thomas Date: Monday, January 10, 2022 at 1:52 AM To: users@tomcat.apache.org Subject: Re: HTTP2 : WINDOW_UPDATE not sent on stream level On 10/01/2022 07:23, Arshiya Shariff wrote: > Thank you for the response Mark . > > Yes, with the default window size the requests process fine . > > We were just attempting to reproduce the original issue that we are facing in > production with version 9.0.38 where few connections go unresponsive for few > seconds around the same time i.e. tomcat is able to receive the > headers/partial data, but not responding back with window_update or sending > ping frames and then after sometime tomcat sends PING frame and the > connection processes further requests successfully . The GC looks fine at > that time. > > Could there be any reasons that can cause this ? Please let us know. The behaviour you saw with 9.0.38 is likely to be a known bug that is fixed in 9.0.56. From the changelog: https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fbz.apache.org%2Fbugzilla%2Fshow_bug.cgi%3Fid%3D65179data=04%7C01%7Cdwhitfield%40perforce.com%7C8c32c6efff5f492ddb9e08d9d40e1007%7C95b666d19a7549ab95a38969fbcdc08c%7C0%7C0%7C637773979411880749%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000sdata=yQG8pgfLrw6ED9tbG5m5JvKuhEljcsIC4RpvIqmPEl8%3Dreserved=0 Ensure that the connection level flow control window from the client to the server is updated when handling DATA frames received for completed streams else the flow control window may become exhausted. It could also be: Correct bugs in the HTTP/2 connection flow control management that meant it was possible for a connection to stall waiting for a connection flow control window update that had already arrived. Any streams on that connection that were trying to write when this happened would time out. I think the first entry is more likely but it could be either. If you want to be reasonably sure which it is, test with versions 9.0.44, 9.0.45, 9.0.48 and 9.0.50. If you want to be really sure, build Tomcat from source for the commits just before and just after each fix and test with those builds. Mark This e-mail may contain information that is privileged or confidential. If you are not the intended recipient, please delete the e-mail and any attachments and notify us immediately.
Re: HTTP2 : WINDOW_UPDATE not sent on stream level
On 10/01/2022 07:23, Arshiya Shariff wrote: Thank you for the response Mark . Yes, with the default window size the requests process fine . We were just attempting to reproduce the original issue that we are facing in production with version 9.0.38 where few connections go unresponsive for few seconds around the same time i.e. tomcat is able to receive the headers/partial data, but not responding back with window_update or sending ping frames and then after sometime tomcat sends PING frame and the connection processes further requests successfully . The GC looks fine at that time. Could there be any reasons that can cause this ? Please let us know. The behaviour you saw with 9.0.38 is likely to be a known bug that is fixed in 9.0.56. From the changelog: https://bz.apache.org/bugzilla/show_bug.cgi?id=65179 Ensure that the connection level flow control window from the client to the server is updated when handling DATA frames received for completed streams else the flow control window may become exhausted. It could also be: Correct bugs in the HTTP/2 connection flow control management that meant it was possible for a connection to stall waiting for a connection flow control window update that had already arrived. Any streams on that connection that were trying to write when this happened would time out. I think the first entry is more likely but it could be either. If you want to be reasonably sure which it is, test with versions 9.0.44, 9.0.45, 9.0.48 and 9.0.50. If you want to be really sure, build Tomcat from source for the commits just before and just after each fix and test with those builds. Mark Thanks and Regards Arshiya Shariff -Original Message- From: Mark Thomas Sent: Wednesday, January 5, 2022 2:36 PM To: users@tomcat.apache.org Subject: Re: HTTP2 : WINDOW_UPDATE not sent on stream level On 05/01/2022 06:14, Arshiya Shariff wrote: Hi Team, On sending 3 requests of around 3KB size , we see that only the first request has processed fine. The other 2 requests are waiting for more Data as tomcat has not responded with WINDOW_UPDATE on stream level . Please help us understand this behavior . Embedded tomcat version : 9.0.56 The initial window size is set to 500, all other params are the tomcat defaults . HTTP2 port : 1080 Client : JMeter I have placed the reproducer , debug logs ,PCAP and JMX where we have tested with version 9.0.56 here : https://protect2.fireeye.com/v1/url?k=31323334-501d5122-313273af-45444 731-d40684d89713d0eb=1=8a27bb36-1eab-4d6a-bee6-03760f68d928= https%3A%2F%2Fdrive.google.com%2Ffile%2Fd%2F1u4Sc_7oSB9tdJN8ls9xTMrRqP 8IFoACM%2Fview%3Fusp%3Dsharing The same JMX works fine with the overhead values changed to zero. Which indicates the requests you are sending are triggering the excessive overhead protection code. Will we have any side effects on changing the overhead parameters to zero? For Tomcat, generally not since it wasn't vulnerable to the various HTTP/2 DoS attacks that were popular a few years ago. The overhead protection was added primarily as a way to detect and reject clients exhibiting abusive behaviour. Looking at your source code you have set the HTTP/2 initial window size to 500. That is far too low. Since it is lower than the default overhead threshold for data (1024) it means every single DATA frame is going to be classed as abusive. No wonder the connection gets closed down so quickly. If you set the default window size to something sensible - or just leave it as the default - do you still see the issue? Mark - 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
RE: HTTP2 : WINDOW_UPDATE not sent on stream level
Thank you for the response Mark . Yes, with the default window size the requests process fine . We were just attempting to reproduce the original issue that we are facing in production with version 9.0.38 where few connections go unresponsive for few seconds around the same time i.e. tomcat is able to receive the headers/partial data, but not responding back with window_update or sending ping frames and then after sometime tomcat sends PING frame and the connection processes further requests successfully . The GC looks fine at that time. Could there be any reasons that can cause this ? Please let us know. Thanks and Regards Arshiya Shariff -Original Message- From: Mark Thomas Sent: Wednesday, January 5, 2022 2:36 PM To: users@tomcat.apache.org Subject: Re: HTTP2 : WINDOW_UPDATE not sent on stream level On 05/01/2022 06:14, Arshiya Shariff wrote: > Hi Team, > On sending 3 requests of around 3KB size , we see that only the first > request has processed fine. The other 2 requests are waiting for more Data as > tomcat has not responded with WINDOW_UPDATE on stream level . Please help us > understand this behavior . > > Embedded tomcat version : 9.0.56 > The initial window size is set to 500, all other params are the tomcat > defaults . > HTTP2 port : 1080 > Client : JMeter > > I have placed the reproducer , debug logs ,PCAP and JMX where we have tested > with version 9.0.56 here : > https://protect2.fireeye.com/v1/url?k=31323334-501d5122-313273af-45444 > 731-d40684d89713d0eb=1=8a27bb36-1eab-4d6a-bee6-03760f68d928= > https%3A%2F%2Fdrive.google.com%2Ffile%2Fd%2F1u4Sc_7oSB9tdJN8ls9xTMrRqP > 8IFoACM%2Fview%3Fusp%3Dsharing > > The same JMX works fine with the overhead values changed to zero. Which indicates the requests you are sending are triggering the excessive overhead protection code. > Will we have any side effects on changing the overhead parameters to zero? For Tomcat, generally not since it wasn't vulnerable to the various HTTP/2 DoS attacks that were popular a few years ago. The overhead protection was added primarily as a way to detect and reject clients exhibiting abusive behaviour. Looking at your source code you have set the HTTP/2 initial window size to 500. That is far too low. Since it is lower than the default overhead threshold for data (1024) it means every single DATA frame is going to be classed as abusive. No wonder the connection gets closed down so quickly. If you set the default window size to something sensible - or just leave it as the default - do you still see the issue? Mark - 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
Re: HTTP2 : WINDOW_UPDATE not sent on stream level
On 05/01/2022 06:14, Arshiya Shariff wrote: Hi Team, On sending 3 requests of around 3KB size , we see that only the first request has processed fine. The other 2 requests are waiting for more Data as tomcat has not responded with WINDOW_UPDATE on stream level . Please help us understand this behavior . Embedded tomcat version : 9.0.56 The initial window size is set to 500, all other params are the tomcat defaults . HTTP2 port : 1080 Client : JMeter I have placed the reproducer , debug logs ,PCAP and JMX where we have tested with version 9.0.56 here : https://drive.google.com/file/d/1u4Sc_7oSB9tdJN8ls9xTMrRqP8IFoACM/view?usp=sharing The same JMX works fine with the overhead values changed to zero. Which indicates the requests you are sending are triggering the excessive overhead protection code. Will we have any side effects on changing the overhead parameters to zero? For Tomcat, generally not since it wasn't vulnerable to the various HTTP/2 DoS attacks that were popular a few years ago. The overhead protection was added primarily as a way to detect and reject clients exhibiting abusive behaviour. Looking at your source code you have set the HTTP/2 initial window size to 500. That is far too low. Since it is lower than the default overhead threshold for data (1024) it means every single DATA frame is going to be classed as abusive. No wonder the connection gets closed down so quickly. If you set the default window size to something sensible - or just leave it as the default - do you still see the issue? Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
HTTP2 : WINDOW_UPDATE not sent on stream level
Hi Team, On sending 3 requests of around 3KB size , we see that only the first request has processed fine. The other 2 requests are waiting for more Data as tomcat has not responded with WINDOW_UPDATE on stream level . Please help us understand this behavior . Embedded tomcat version : 9.0.56 The initial window size is set to 500, all other params are the tomcat defaults . HTTP2 port : 1080 Client : JMeter I have placed the reproducer , debug logs ,PCAP and JMX where we have tested with version 9.0.56 here : https://drive.google.com/file/d/1u4Sc_7oSB9tdJN8ls9xTMrRqP8IFoACM/view?usp=sharing The same JMX works fine with the overhead values changed to zero. Will we have any side effects on changing the overhead parameters to zero? Thanks in Advance! Regards Arshiya Shariff
