Bug 47797

Summary: The body of the request is lost when you send the POST method !
Product: Tomcat 6 Reporter: Eugene <johnbat26>
Component: CatalinaAssignee: Tomcat Developers Mailing List <dev>
Status: RESOLVED WORKSFORME    
Severity: critical CC: kame
Priority: P2    
Version: 6.0.13   
Target Milestone: default   
Hardware: PC   
OS: Linux   
Attachments: tcpdump with lost body of post request
TestCase with only Servlet
My Http11Processor class
My InputBuffer
My StandardEngineValve

Description Eugene 2009-09-08 00:25:08 UTC
Hello!
I have a critical issue, most likely associated with Tomcat 5.5.X.
------------------------------
My environment:
OS: RHEL 5 x86 or x86-64;
JVM: sun-jdk-1.6.0.16 or jrockit-R27.5.0-jdk1.6.0_03;
AS: Jboss AS 4.2.2.GA (with Tomcat 5.5.X (JBossWeb-2.0.1.GA ) inside)
------------------------------
I implemented web-service using apache xml-rpc 3.1.2.	
Then I call it from the http client. (apache httpclient 4.0).
This my request:
------------------------------------------
POST /cas-services-verimatrix-pull/pull HTTP/1.1

Host: 10.20.2.150:8080

Accept: */*

Content-Type: text/xml

Content-Length: 391



<?xml version="1.0" encoding="UTF-8"?>

<methodCall>

<methodName>EISTMPull.getEntitlement</methodName>

<params>

<param><value><string>00020215B9FE</string></value></param>

<param><value><base64>



</base64></value></param>

<param><value><array><data>

<value><string>DTV</string></value>

<value><string>PPV</string></value>

</data></array></value></param>

</params>

</methodCall>
-----------------------------------------------

This request is almost always handled properly.But sometimes the body of the HTTP request is lost and the server sends a reply, as if the request body is empty:
-----------------------------------------------
HTTP/1.1 200 OK

Server: Apache-Coyote/1.1

X-Powered-By: Servlet 2.4; JBoss-4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)/Tomcat-5.5

Content-Type: text/xml

Content-Length: 312

Date: Fri, 07 Aug 2009 15:16:19 GMT



<?xml version="1.0"?><methodResponse><fault><value><struct><member><name>faultString</name><value>java.lang.NoSuchMethodException:&#32;ru.cti.oss.cas.verimatrix.pull.Pull.getEntitlement()</value></member><member><name>faultCode</name><value><int>0</int></value></member></struct></value></fault></methodResponse>
-----------------------------------------------

First used xml-rpc version 2, then I updated it to 3.1.2. Accordingly, the error must be at the level of tomcat.

I fulfilled a lot of tests. This error does not depend on the load application server. Fortuitous. But because of this, our clients can not work normally. Therefore, I think this problem critical.

Please, help with what could be wrong?
	
Thanks in advance.
Comment 1 Eugene 2009-09-08 00:26:17 UTC
Created attachment 24223 [details]
tcpdump with lost body of post request
Comment 2 Eugene 2009-09-08 00:42:31 UTC
My Catalina setting:

<Connector port="8080" address="${jboss.bind.address}"    
         maxThreads="250" maxHttpHeaderSize="8192"
         emptySessionPath="true" protocol="HTTP/1.1"
         enableLookups="false" redirectPort="8443" acceptCount="100"
         connectionTimeout="20000" disableUploadTimeout="true"/>
Comment 3 Mark Thomas 2009-09-08 13:41:08 UTC
The fact that the NoSuchMethodException is returned and references the method declared in the request body clearly demonstrates that the issue is with the framework or the application not with Tomcat.
Comment 4 Eugene 2009-09-13 23:55:03 UTC
(In reply to comment #3)
> The fact that the NoSuchMethodException is returned and references the method
> declared in the request body clearly demonstrates that the issue is with the
> framework or the application not with Tomcat.

I assure you that the error at Tomcat.
Because after the expansion logging all talking about it. And at the servlet level is already coming InputStream, whose size =- 1!

NoSuchMethodException emerged, when from catalina level receive empty body of POST Request. And parser begin to analyze empty xml !

After update xmlrpc up to 3.1.2 I became  receive other error:
-----------------------
14:58:37,017 ERROR [XmlRpcErrorLogger] Failed to parse XML-RPC request: Premature end of file.                                              
org.apache.xmlrpc.XmlRpcException: Failed to parse XML-RPC request: Premature end of file. 
-----------------------
	
This is not always the case. And from time to time, and says that comes a blank document! That is the request body is empty, even though all the headlines come to normal! Also, the server always send the same request. See attached dump. 

Error occurred in CoyoteAdapter.service():
 in line:
----------------
  connector.getContainer().getPipeline().getFirst().invoke(request, response);
----------------
Please, help me.
Comment 5 Mark Thomas 2009-09-14 01:19:10 UTC
There is nothing in this bug report or the attached dump that indicates a problem at the Tomcat level (or JBoss for that matter).

The attached dump shows 4 requests. Looking at the first request in detail:

The request body declares the method that the client wishes to call: EISTMPull.getEntitlement

The response (with an HTTP status of 200 OK) includes the NoSuchMethodException that references the name of the method declared in the body. Clearly, the body was read correctly since the method name has been read *from the body*.

Whilst I understand you are having problems, there is nothing in this report that demonstrates a Tomcat issue. In the absence of a demonstrated Tomcat issue, this bug in INVALID.
Comment 6 Eugene 2009-09-15 04:17:49 UTC
Periodically, the body disappears POST-request with the same query! 
I wrote a test client. It httpClient sends a test request, and on the server side, the servlet it takes. And trying to read.
Sometimes there is a situation that the titles are coming, but the body is absent. 
That is, when reading req.getInputStream().read(...) we obtain -1. 
This error appears periodically. Tested on JBoss-4.2.2.GA with Tomcat 5.5.X. 
Please, help me!
Comment 7 Eugene 2009-09-15 04:19:07 UTC
Created attachment 24267 [details]
TestCase with only Servlet

testcase
Comment 8 Mark Thomas 2009-09-15 13:05:30 UTC
I ran your test case with 10000 iterations on both trunk and 5.5.x with no failures. Whatever the root cause is of the issue you are seeing, it isn't Tomcat.
Comment 9 Eugene 2009-09-28 22:31:54 UTC
Again rediscovered this bug.
The reason is as follows.
1. This problem occurs not every time, but we have it in a production environment there is very often that annoys customers.

2. This test should be run on version 5.5.21, or that what is included in JBoss. And we need to at least day it worked.

3. The most important thing! I replaced the tomcat in JBoss 4.2.2.GA on Jetty 6.1.18 and the problem disappeared. I think this clearly indicates that the problem is inside Tomcat.

4. The fact that we can not take the latest version of tomcat from the fact that JBoss is tightly integrated. : (

5. I repeat that the titles always come and parsed fine. But it is the body of POST-request is lost. No matter what the parser chooses the remaining data from the stream. Always returns -1!
	
Thanks in advance for understanding.
Comment 10 Eugene 2009-09-28 22:38:34 UTC
Requests differ only in time of shipment and port of the sender. Headers are always the same!
Maybe tells where to look? And what place might happen this error? And on what terms, titles, etc. it may depend.
Comment 11 Mark Thomas 2009-09-29 05:00:38 UTC
If this issue is with 5.5.21 and I can't reproduce it with 5.5.x then it has already been fixed.

Tomcat does not provide patches for older versions. Upgrading is your only option. You would be best following this up with the JBoss folks.
Comment 12 Eugene 2009-10-01 22:20:08 UTC
I embed several count of code in Http11Processor and StandardEngineValve.
In Http11Processor,process() I added next after invoke    inputBuffer.parseRequestLine();  :
------------
 if (request.unparsedURI().equals("/lost-post/generic"))
        {                    log.error("----------------------------------------------------------");
   StringBuffer stringBuffer = new StringBuffer();                                    
                    for (int i = 0; i < inputBuffer.buf.length; i++) {
                        stringBuffer.append((char) inputBuffer.buf[i]);
                    }
                                                                               
                    log.error(stringBuffer);
                    log.error("LENGTH: "+ inputBuffer.buf.length);                                      
                    log.error("++++++++++++++++++++++++++++++++++++++++++++++");                    
                }
------------

and in StandardEngineValve.invoke() I added next code:
-----------------------
    if (request.getWrapper().getName().equals("LostPostGenericServlet"))
        {
            log.error("-----------------------------------------------------------------------------");
            StringBuffer stringBuffer = new StringBuffer();
            InputStream input = request.getInputStream();
            int i=request.getContentLength();
            int c;
            while (((c = input. read()) != -1) && (--i > 0)) {
                stringBuffer.append((char) c);
            }
            input.close();
                            
            log.error(stringBuffer);
            PrintWriter out = response.getWriter();
            if (stringBuffer.length() > 0) {
                StringBuffer xmlBuffer = new StringBuffer();
                xmlBuffer.append("<?xml version='1.0' encoding='UTF-8'?>");
                xmlBuffer.append("<methodCall>");
                xmlBuffer.append("OK");
                xmlBuffer.append("</methodCall>");
                out.print(xmlBuffer);
                System.out.println("OK");
            } else {
                StringBuffer xmlBuffer2 = new StringBuffer();
                xmlBuffer2.append("<?xml version='1.0' encoding='UTF-8'?>");
                xmlBuffer2.append("<methodCall>");
                xmlBuffer2.append("FAILED");
                xmlBuffer2.append("</methodCall>");
                out.print(xmlBuffer2);                        
                System.out.println("FAILED");
            }
            out.close();
            log.error("++++++++++++++++++++++++++++++++++++++++++++++");
            return;
        }

-----------------------
So added code in Http11Processor print entire buffer, whereas code in StandardEngineValve print content of body from CoyoteInputStream.
When I increase loading at tomcat (with help of Grinder) happen this error,
and code in Http11Processor print normal request with body, whereas code in StandardEngineValve print empty string:
**********************
...
2009-10-01 20:11:30,588 ERROR [Http11Processor] -----------------------------------------------------------------------------
2009-10-01 20:11:30,589 ERROR [Http11Processor] POST /lost-post/generic HTTP/1.1
Accept-Encoding: gzip,deflate
Content-Type: text/xml;charset=UTF-8
SOAPAction: ""
User-Agent: Jakarta Commons-HttpClient/3.1
Host: 172.20.0.3:8080
Content-Length: 389

<?xml version="1.0" encoding="UTF-8"?>

<methodCall>

<methodName>EISTMPull.getEntitlement</methodName>

<params>

<param><value><string>00020215B9FE</string></value></param>

<param><value><base64>

</base64></value></param>

<param><value><array><data>

<value><string>DTV</string></value>

<value><string>PPV</string></value>

</data></array></value></param>

</params>

</methodCall>e2:$Version="1""

ntent-type:application/x-www-form-urlencoded; charset=UTF-88
content-length:633

j_username=00%3A02%3A02%3A14%3A47%3A2e&j_password=702007D314410    
2009-10-01 20:11:30,589 ERROR [Http11Processor] LENGTH: 8192
2009-10-01 20:11:30,589 ERROR [Http11Processor] ++++++++++++++++++++++++++++++++++++++++++++++
2009-10-01 20:11:30,589 ERROR [StandardEngineValve] -----------------------------------------------------------------------------
2009-10-01 20:11:30,589 ERROR [StandardEngineValve] 
2009-10-01 20:11:30,590 ERROR [StandardEngineValve] ++++++++++++++++++++++++++++++++++++++++++++++
......
*************************************                                                                                                                       
                                                                                                    Therefore error happen inside tomcat ! During parsing body of request. Often this happen during increase loading at other applications deployed in tomcat.

I conclude several tomcat classes, which uses in JBossWeb, because don't know, which version of tomcat 5.5 used in JbossWeb 2.0.3.GA
	
Many thanks in advance for any some help.
Comment 13 Eugene 2009-10-01 22:21:35 UTC
Created attachment 24330 [details]
My Http11Processor class
Comment 14 Eugene 2009-10-01 22:24:07 UTC
Created attachment 24331 [details]
My InputBuffer
Comment 15 Eugene 2009-10-01 22:27:48 UTC
Created attachment 24332 [details]
My StandardEngineValve
Comment 16 Eugene 2009-10-01 22:29:09 UTC
This is link to svn at JBossWeb with tomcat 5.5.X inside:
http://anonsvn.jboss.org/repos/jbossweb/branches/2.0.x
Comment 17 Eugene 2009-10-02 00:56:13 UTC
Amenably table: http://www.jboss.org/community/wiki/VersionOfTomcatInJBossAS
and post at forum: http://www.jboss.org/index.html?module=bb&op=viewtopic&t=161900

versin tomcat in Jboss-4.2.2.GA >= 6.0.13
Comment 18 Eugene 2009-10-02 03:24:47 UTC
I changed connector to Http11NioConnector:
<Connector port="8080" address="${jboss.bind.address}"
         protocol="org.apache.coyote.http11.Http11NioProtocol"
          redirectPort="8443"/>

this problem persist :(
Comment 19 Eugene 2009-10-02 05:15:44 UTC
I patched InputBuffer from  bug  44673, problem persist :(
Comment 20 Eugene 2009-10-02 06:20:14 UTC
I added:
  public int read(byte[] b, int off, int len) throws IOException {
        if (closed)
            throw new IOException(sm.getString("inputBuffer.streamClosed"));
        return bb.substract(b, off, len);
    }

now tomcat throw exception, that streamClosed!!!
someone close stream, and later try read from buffer !
Please, give me full patch at 44673 bug? ;)
Comment 21 Damien Bonvillain 2009-10-02 08:38:54 UTC
Just a quick history note: I opened #44673 because I had a real problem of POST body lost. In my case: a servlet reads the request body directly from request.getInputStream(), and nothing happens. Tracing that call, the VM is stuck in a native call to read0 on the socket. Extremely hard to reproduce in my case. Dumping the network traffic, the cases we found so far were that the POST query was sent as two packets by IE, and the second packet was missing, but not missing as a dropped packet but more like the client didn't bother of sending it. More precisely, the client sent the first packet, which was ACKnowledged by the server... and when the IE browser was killed (in that case, the IE client is frozen) the RST,ACK packet sent by the client matches the TCP sequence number specified by the ACK packet sent by the server.

So, basically, Tomcat received a POST request with a Content-Length header specifying there were more bytes to read, the Servlet reads from the InputStream, then Tomcat fills its buffer and ends up in blocking IO... unblocked only when the client resets the connection.
Comment 22 Mark Thomas 2009-12-14 10:53:12 UTC
In the original report the response includes data that is only available in the request body. Therefore, in that original example, there is clearly no loss of request body.

The test case provided in comment #7 did not reproduce the issue with trunk, the latest code 6.0.x or the latest code from 5.5.x.

Tomcat as embedded in JBoss != Tomcat as provided by the ASF. Since this issue is occurring with Tomcat embedded in JBoss, the JBoss folks are your best source of help.

At the moment, this looks like either:
a) an issue with the JBoss integration
b) an issue in 5.5.21 / 6.0.13  that has since been fixed

If it is a) then the Tomcat community can't help you.
If it is b) then the Tomcat community can only suggest that you upgrade the version of Tomcat you are using. If that isn't possible because you are using JBoss you'll need to seek help from the JBoss community.

Please do not re-open this bug unless you can provide a test case that reproduces this problem (however infrequently) on a clean installation of the latest stable Apache Tomcat 5.5.x or 6.0.x release. At the time of writing this comment those versions are 5.5.28 and 6.0.20.