Bug 67670 - 20 seconds to download some JS files with 9.0.81
Summary: 20 seconds to download some JS files with 9.0.81
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 9
Classification: Unclassified
Component: Connectors (show other bugs)
Version: 9.0.81
Hardware: PC Linux
: P2 regression (vote)
Target Milestone: -----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
: 67678 67685 (view as bug list)
Depends on:
Blocks:
 
Reported: 2023-10-10 20:41 UTC by M McClain
Modified: 2023-10-11 21:28 UTC (History)
4 users (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description M McClain 2023-10-10 20:41:45 UTC
After upgrading to Tomcat 9.0.81 from 9.0.80, I'm seeing some static JavaScript assets take 20 seconds to return.  The page rendering freezes while this is happening.

I bisected the code between 9.0.80 and 9.0.81 and the following commit appears to be responsible.


commit eca8f44c766c380c0d117dc7eca9d933aea71c38 (HEAD)
Author: shin-mallang <huipulci1@naver.com>
Date:   Sat Sep 9 22:09:03 2023 +0900

    Relocate the useCompression check and apply parts back to back.

diff --git a/java/org/apache/coyote/http11/Http11Processor.java b/java/org/apache/coyote/http11/Http11Processor.java
index aab2290407..ac531ad105 100644
--- a/java/org/apache/coyote/http11/Http11Processor.java
+++ b/java/org/apache/coyote/http11/Http11Processor.java
@@ -914,12 +914,6 @@ public class Http11Processor extends AbstractProcessor {
             prepareSendfile(outputFilters);
         }
 
-        // Check for compression
-        boolean useCompression = false;
-        if (entityBody && sendfileData == null) {
-            useCompression = protocol.useCompression(request, response);
-        }
-
         MimeHeaders headers = response.getMimeHeaders();
         // A SC_NO_CONTENT response may include entity headers
         if (entityBody || statusCode == HttpServletResponse.SC_NO_CONTENT) {
@@ -956,8 +950,11 @@ public class Http11Processor extends AbstractProcessor {
             }
         }
 
-        if (useCompression) {
-            outputBuffer.addActiveFilter(outputFilters[Constants.GZIP_FILTER]);
+        // Check for compression
+        if (entityBody && sendfileData == null) {
+            if (protocol.useCompression(request, response)) {
+                outputBuffer.addActiveFilter(outputFilters[Constants.GZIP_FILTER]);
+            }
         }
 
         // Add date header unless application has already set one (e.g. in a
Comment 1 Konstantin Kolinko 2023-10-10 21:59:57 UTC
From a mail by Amit Pande on users' list
> Subject: Tomcat upgrade from 9.0.80 to 9.0.81
https://lists.apache.org/thread/hh84wdgmvfkgs0zof14ly8vxgrh1no4j

org.apache.http.ConnectionClosedException: Premature end of Content-Length delimited message body (expected: 4,999; received: 3,040)

Thus apparently the Content-Length header is set to a wrong value when GZip compression is enabled.
Comment 2 Konstantin Kolinko 2023-10-10 22:11:24 UTC
(In reply to M McClain from comment #0)

> diff --git a/java/org/apache/coyote/http11/Http11Processor.java
> b/java/org/apache/coyote/http11/Http11Processor.java
> index aab2290407..ac531ad105 100644
> --- a/java/org/apache/coyote/http11/Http11Processor.java
> +++ b/java/org/apache/coyote/http11/Http11Processor.java
> @@ -914,12 +914,6 @@ public class Http11Processor extends AbstractProcessor {
> ...
>  
> -        // Check for compression
> -        boolean useCompression = false;
> -        if (entityBody && sendfileData == null) {
> -            useCompression = protocol.useCompression(request, response);
> -        }
> ...
> @@ -956,8 +950,11 @@ public class Http11Processor extends AbstractProcessor {

The lines between the two chunks in the diff above in Http11Processor are responsible for setting the "Content-Length" header.

>930:        long contentLength = response.getContentLengthLong();
>...
>937:        } else if (contentLength != -1) {
>938:            headers.setValue("Content-Length").setLong(contentLength);


The "protocol.useCompression(request, response)" call goes down to
org.apache.coyote.CompressionConfig#useCompression(...) that does

>        // Compressed content length is unknown so mark it as such.
>        response.setContentLength(-1);
>        // Configure the content encoding for compressed content
>        responseHeaders.setValue("Content-Encoding").setString("gzip");

As the "useCompression" was moved by that commit, line 930 no longer sees the correct contentLength value.


Note: The workaround for this issue is to turn off compression on a Connector. (Remove the "compression" attribute from a <Connector> element, or set it to "off").

https://tomcat.apache.org/tomcat-9.0-doc/config/http.html#Standard_Implementation
Comment 3 Konstantin Kolinko 2023-10-10 22:48:13 UTC
I have not tested yet, but I guess that Tomcat 8.5.94, 10.1.14 and 11.0.0-M12 are affected as well.

The code regarding useCompression() call (o.a.c.http11.Http11Processor, o.a.c.CompressionConfig) is essentially the same. Commits:

8.5.x: https://github.com/apache/tomcat/commit/7abdf0b44c79f65c4f0fc862a1ea311f81ce881a

10.1.x: https://github.com/apache/tomcat/commit/97c58599b25107d5b5cc19dd199a4fa847e99358

main (11.0.x): https://github.com/apache/tomcat/commit/e47d0c46fecb3745593e9b4552e4298adf8184d2
Comment 4 Remy Maucherat 2023-10-11 07:01:40 UTC
Sorry. I complained about this refactoring, but unfortunately could not find anything obviously wrong with it, so it went in ...
Comment 5 Remy Maucherat 2023-10-11 08:01:49 UTC
Thanks Konstantin for the review of the issue.

The fix will be in 11.0.0-M13, 10.1.15, 9.0.82 and 8.5.95.

I assume the release process for the next round of releases will start soon (likely a couple days due to the conference, we'll see).
Comment 6 Han Li 2023-10-11 09:46:06 UTC
*** Bug 67678 has been marked as a duplicate of this bug. ***
Comment 7 Mark Thomas 2023-10-11 09:54:19 UTC
(In reply to Remy Maucherat from comment #4)
> Sorry. I complained about this refactoring, but unfortunately could not find
> anything obviously wrong with it, so it went in ...

Sorry, I missed this and pushed for this contribution to be accepted. Thanks for the fix and test case.
Comment 8 Remy Maucherat 2023-10-11 10:03:05 UTC
(In reply to Mark Thomas from comment #7)
> (In reply to Remy Maucherat from comment #4)
> > Sorry. I complained about this refactoring, but unfortunately could not find
> > anything obviously wrong with it, so it went in ...
> 
> Sorry, I missed this and pushed for this contribution to be accepted. Thanks
> for the fix and test case.

I couldn't see any problem either, probably because a lot of the code had to be moved to compression config.

So I suppose we have to start a round of releases. Is anyone actually available today ?
Comment 9 Remy Maucherat 2023-10-11 21:28:49 UTC
*** Bug 67685 has been marked as a duplicate of this bug. ***