Bug 57476 - Incomplete html pages
Incomplete html pages
Status: RESOLVED FIXED
Product: Tomcat 8
Classification: Unclassified
Component: Catalina
8.0.17
PC All
: P2 normal (vote)
: ----
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2015-01-21 15:29 UTC by alexandre
Modified: 2015-01-22 21:00 UTC (History)
1 user (show)



Attachments
Buffer test .war as requested by Mark (1.80 KB, application/octet-stream)
2015-01-22 17:39 UTC, Shaun Morton
Details

Note You need to log in before you can comment on or make changes to this bug.
Description alexandre 2015-01-21 15:29:30 UTC
Hello,
I upgrade Tomcat from 8.0.15 to 8.0.17.
I'm using SSL on tomcat server and I disabled port 80. 
with version 8.0.15 everything is fine
with version 8.0.17 for my applications a lot of html pages are incomplete, and some applications stop responding after using them some minutes.
I downgrade to 8.0.15 to have no problem. 
Nothing in tomcat logs.
I don't know where is the problem (tomcat, my applications, ...), just want to give you this information.
Thank you, Kind regards,
Alexandre.
Comment 1 Mark Thomas 2015-01-21 15:40:49 UTC
Which connector are you using? Does the problem stop if you switch connectors?

Is sendFile enabled? If yes, does the problem stop if sendFile is disabled?

Thread dump (ideally 3, ~10s apart) when the application stops responding?

Please provide the logs from the time the issue occurs. They may tell us something they don't tell you.
Comment 2 Marco 2015-01-21 22:46:53 UTC
Hello,

same problem.
After a last jsp:include in a jsp site the html content is not shown.
No errors in tomcat log. Default Tomcat with port 8080.
Comment 3 Christopher Schultz 2015-01-21 22:50:30 UTC
I have a single JSP running on 8.0.17 with 4 includes, and the page works just fine. Can you give more information about your environment? There's also a thread on the dev list if you want to discuss.
Comment 4 Marco 2015-01-21 23:58:32 UTC
I make a little test. I add a <%out.flush();%> at the end of the jsp file and the html content is correct. Without the <%out.flush();%> the html content is broken.
Comment 5 reibitto 2015-01-22 04:56:43 UTC
I'm seeing similar issues with version 8.0.17 as well. Downgrading back to 8.0.15 made the problems go away for me, so it seems like something introduced between these versions is causing this.

So far I've only noticed this problem with JSP files. Static content seems unaffected. Also, I'm seeing this happen through both HTTP and HTTPS.

When the response is being truncated, the resulting size is always multiples of 8192 bytes. But this seems to only happen only if the resulting size is anything greater than 16KB. Examples of what I'm seeing:

Expected size / Actual response size
anything less than 16 KB -> the response is fine
17 KB -> 8 KB
25 KB -> 16 KB
39 KB -> 24 KB
44 KB -> 32 KB
50 KB -> 40 KB

So it seems like the last remaining block (or 2?) isn't being written out... assuming the buffer size is 8 KB. And yes, when I call out.flush(), this problem goes away for me too.

Here's some information about my environment:
Java(TM) SE Runtime Environment (build 1.8.0_25-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.25-b02, mixed mode)
OS X Yosemite 10.10.1
Comment 6 Leandro 2015-01-22 07:14:29 UTC
I'm facing exactly the same issue. I've noticed that putting <% out.flush() %> at the end of the JSP file, everything was OK, but It's not good to assume that it's the goal to solve that.
Comment 7 Konstantin Kolinko 2015-01-22 08:13:56 UTC
This still lacks a reproduction recipe.

Thus far I tried the following simple tests with 8.0.17, and all of them are working (except a minor issue filed as bug 57481)

- static files (Tomcat binaries)
- examples webapp (mostly useless, as those pages are small)
- simple jsp with a lot of text  (200Kb)
- jsp with jsp:include with a lot of text (200Kb, 800Kb)
- simple jsp with EL (122Kn)
- simple jsp with tags (164Kb)

I tested
HTTP + (bio,nio,apr) + (with Executor or without Executor)
HTTPS + (bio,nio) + without Executor

I am using JDK 7u72 (32-bit) on Windows 7.

No truncations noted.

Something else is needed to reproduce this.
Comment 8 reibitto 2015-01-22 10:47:07 UTC
Okay, after some debugging, I think I found how to duplicate this rather easily. The original project where this was happening for me was a Spring MVC project. I wasn't able to duplicate it in a non-Spring MVC project at first, so I went back to my original project and followed the path from beginning to end to get more clues as to what was happening. I found that the bug seems to only occur when requests are forwarded. After realizing that, I was able to create a minimal example that shows the problem:

1. Download a fresh stock 8.0.17 build
2. Drop in two JSP files in webapps/ROOT (the Tomcat welcome screen project is perfectly fine). For example: page1.jsp and page2.jsp
3. Put <% request.getRequestDispatcher("page2.jsp").forward(request, response); %> in page1.jsp
4. Put a bunch of plain text (you don't need dynamic content) in page2.jsp so that the response will be over 16 KB.
5. Now visit localhost:8080/page1.jsp in your browser, and notice the content being truncated.

Also, note that going to localhost:8080/page2.jsp directly does NOT truncate the data because there is no forwarding happen there.

I was able to duplicate this on 2 separate machines (Mac and Windows).
Comment 9 Mark Thomas 2015-01-22 10:53:38 UTC
Thanks for the extra info. I (and I suspect a few other committers as well) am looking at this now...
Comment 10 Mark Thomas 2015-01-22 10:59:45 UTC
Reprodcued every time. Many thanks. Looking for the root cause at the moment...
Comment 11 Mark Thomas 2015-01-22 11:40:18 UTC
I've found the root cause. It was triggered by r1643210 but I think all that did was uncover a different bug.

It is easier to see if you go back to Tomcat 6 as that is before async was added. If you look at StandardHostValve line 136 [1] you'll see that the response is unsuspended unconditionally although the comment suggests it is being unsuspended for error handling (which may need to write to the response).

In r1643210 that code was modified so the response was only unsuspended if there was an error to handle.

This triggered the problem because the RequestDispatcher did not flush the response before calling finish(). Calling finish() sets suspended to true. The sequence was:
a) page 1 forwards to page 2
b) page 2 writes response leaving some data in buffer
c) RD calls finish which suspends response
d) StandardHostValve unsuspends response
e) normal end handling for page 1 flushes and closes the response

r1643210 removed step d) which in turn prevented the flush in step e).

Section 9.4 of the Servlet 3.1 spec says:
<quote>
Before the forward method of the RequestDispatcher interface returns without exception, the response content must be sent and committed, and closed by the servlet container, unless the request was put into the asynchronous mode.
</quote>

My reading of the spec is that we should be calling response.flushBuffer() before we call finish() in the RequestDispatcher.

I am going to apply a patch to that effect to trunk, 8.0.x and 7.0.x shortly. I then intend to start an 8.0.x release.


[1] http://svn.eu.apache.org/viewvc/tomcat/tc6.0.x/trunk/java/org/apache/catalina/core/StandardHostValve.java?view=annotate#l136
Comment 12 Konstantin Kolinko 2015-01-22 11:43:07 UTC
Thank you! Reproduced based on recipe from Comment 8.

My example:
1) webapps/examples2/numberwriter2.jsp:
[[[
Forward to numberwriter.txt
<jsp:forward page="numberwriter.txt" />
]]]

2) webapps/examples2/numberwriter.txt:
Copied output of numberwriter example
(10000 lines with numbers from 00000000000000000001 up to 00000000000000010000,
210000 bytes total (EOL = LF))

I request /examples2/numberwriter2.jsp with wget.
I observe the following pairs of requests in access log file:

127.0.0.1 - - [22/Jan/2015:14:32:00 +0300] "GET /examples2/numberwriter2.jsp HTTP/1.0" 200 204800
127.0.0.1 - - [22/Jan/2015:14:32:20 +0300] "GET /examples2/numberwriter2.jsp HTTP/1.0" 206 5200

That is the first GET request hangs after transferring 204800 bytes. After waiting for 20 seconds wget aborts connection. It repeats request asking for a range of bytes,  and receives remaining 5200 bytes of the file.

This happens in the same way for all connectors that I tested (those mentioned in Comment 7).
Comment 13 Shaun Morton 2015-01-22 17:39:16 UTC
Created attachment 32391 [details]
Buffer test .war as requested by Mark

Mark,
Just in case you still need a test .jsp for this issue.
rowsToPrint in index.jsp is set to break right now.
Comment 14 Mark Thomas 2015-01-22 21:00:32 UTC
This has been fixed in trunk, 8.0.x (for 8.0.18 onwards) and in 7.0.x. Note that the fix that introduced this regression has not been included in a 7.0.x release so no 7.0.x release is affected by this bug.