You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Jason Smith <js...@infotrustgroup.com> on 2009/04/06 20:27:06 UTC

Help with a Tomcat issue???

Sorry for the spam if you are on both newsgroups.  I have been asked to move this to the user's group rather than the developers group.  I still think it's a developer issue, but I am more interested in actually finding answers than arguing the point.

I am using a standard UrlHttpConnection to connect to Tomcat.  When I use setChunkedStreamingMode, no matter what the setting, I start getting bad method names in my servlet.

HttpURLConnection conn = (HttpURLConnection)url.openConnection();
conn.setChunkedStreamingMode(1024);

I am seeing this in my override of the .service() method in the Servlet, which is the earliest point available to me if I stay within the confines of the spec.  The method name comes in as '0\n\nPOST'.  I've tracked this through a bunch of Tomcat classes, working on the 5.5.27 code base.  

I have intercepted the socket InputStream (in Http11BaseProtocol) and looked at the data coming in.  It is what I expect ('POST .').  Yes, let me repeat that, the data coming in from the socket is good.  I've visually inspected it, and it matches the spec.

When I get into the InternalInputBuffer, I am seeing there is data left over at the end of one stream ('0\n\n') which gets appended to the beginning of the next request because of the code in .nextRequest().  It almost looks like someone downstream is not consuming the very last byte in the buffer.

But then why the heck does .nextRequest copy it into the new buffer for the next request?  This makes no sense to me.

So I have verified that the data is coming in right.  And at the very first entry point into the servlet, the method name is messed up.  

This appears to be happening in Tomcat, and has been replicated on a number of machines.

So PLEASE, can ANYONE tell me what .nextRequest() is doing?  It says that *** All bytes of the current request should have been already consumed.***  That is not what I am seeing. And this part of the code isn't dealing with corrupt data very elegantly (it assumes that everything is perfect).

Is this a problem with downstream code, which has a responsibility to consume every byte in the input stream? Or is it bad code in nextRequest(), which really should not be taking the tail of one request and appending it to the next?  Or is it something else?

Thanks!  See below for more info.



From: Jason Smith 
Sent: Monday, April 06, 2009 11:08 AM
To: 'dev@tomcat.apache.org'
Subject: RE: Help with a Tomcat bug.

More info.  In InternalInputBuffer.nextRequest(), I noticed there is code to pull remaining bytes into the current buffer before switching.  

    /**
     * End processing of current HTTP request.
     * Note: All bytes of the current request should have been already 
     * consumed. This method only resets all the pointers so that we are ready
     * to parse the next HTTP request.
     */
    public void nextRequest()
        throws IOException {

        // Recycle Request object
        request.recycle();

        // Determine the header buffer used for next request
        byte[] newHeaderBuf = null;
        if (buf == headerBuffer1) {
            newHeaderBuf = headerBuffer2;
        } else {
            newHeaderBuf = headerBuffer1;
        }

        // Copy leftover bytes from buf to newHeaderBuf
        System.arraycopy(buf, pos, newHeaderBuf, 0, lastValid - pos);
        if(lastValid-pos > 0)
        {
            System.out.println("@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@");
            System.out.println("'" + new String(Arrays.copyOf(newHeaderBuf, lastValid - pos), "US-ASCII") + "'");
        }

        // Swap buffers
        buf = newHeaderBuf;

        // Recycle filters
        for (int i = 0; i <= lastActiveFilter; i++) {
            activeFilters[i].recycle();
        }

        // Reset pointers
        lastValid = lastValid - pos;
        pos = 0;
        lastActiveFilter = -1;
        parsingHeader = true;
        swallowInput = true;

    }

I am seeing something like this at one point:

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
'POST /dh/services/jmap/__exists__ HTTP/1.1

But I am also seeing this where this problem is cropping up:

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
'0

'

Anyone got any ideas on how to fix this?  Data from one POST is being carried over to the next POST!!!!!

From: Jason Smith 
Sent: Monday, April 06, 2009 10:16 AM
To: 'dev@tomcat.apache.org'
Subject: Help with a Tomcat bug.

When using .setChunkedStreamingMode(.) from the client, I was getting back an invalid method name in my servlet.  Specifically, in the overridden service() method, the request.getMethod() was returning '0\n\nPOST'.  

I've tracked this all the way into  org.apache.coyote.http11.InternalInputBuffer.  

In .parseRequestLine, the first thing it does is consume leading CRs and LFs.  Well, the first line I am getting is '0\n'.  So it won't consume that line.

The next step parses to the next SPACE character.  So it picks up the 0, the CRs and LFs, all the way to the end of POST.  

The bottom line is that at this point, in this method, the HTTP method name is already messed up.  

Should this be fixed in this method, or is there a better place?

One quick fix:

byte chr = 0;
        do {

            // Read new bytes if needed
            if (pos >= lastValid) {
                if (!fill())
                    throw new EOFException(sm.getString("iib.eof.error"));
            }

            chr = buf[pos++];

        } while ((chr == Constants.CR) || (chr == Constants.LF) || (chr == '0'));


I simply check for the '0' character as well.  This is a bit of a hack, but I don't know the code well enough to know if the leading '0' (which I believe is the last line from a previous chunked POST) is supposed to be there or not.

Any help would be appreciated.  

Tomcat 5.5.27, Java 6u13.

Jason Smith
Software Engineer 
InfoTrust Group, Inc.




---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Help with a Tomcat issue???

Posted by Mark Thomas <ma...@apache.org>.
Jason Smith wrote:
> Just Tomcat, no proxy.  
> 
> And I agree, that isn't the way you'd want to fix it ultimately, but I was experimenting to find out what worked.  You'd ultimately like to not see the '0' at the beginning of the buffer.  I found the place where it was getting copied to the beginning of the buffer, but I can't figure out the logic behind the code.  Too many micro opts (it's fast!).
> 
> What did NOT work was simply subverting the copying of the data and setting the buffer length to 0, as is normally the case.  There are apparently some instances where .nextRequest must copy the data from one buffer to the next.  I tried.  Things didn't work so well after that...  :-)  I mentioned one of those in the previous email.  
> 
> But again, I am not yet familiar with this part of the Tomcat code.  So I am probably missing something fairly obvious.

So, how about some simple code to demonstrate the problem?

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
Me too.  And looking at the source (via Google search), it looks like that is what is was meant to do.  I'm using Sun Java JDK 1.6.0_13.  

-----Original Message-----
From: Christopher Schultz [mailto:chris@christopherschultz.net] 
Sent: Tuesday, April 07, 2009 12:48 PM
To: Tomcat Users List
Subject: Re: Help with a Tomcat issue???

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Jason,

On 4/6/2009 6:33 PM, Jason Smith wrote:
> Sun's implementation of HttpURLConnector apparently creates a new
> ChunkedOutputStream every time you call .getOutputStream().

That's obnoxious and completely unexpected. Latest version of Java, huh?
Too bad. Obviously, the solution is for your client to cache the result
of conn.getOutputStream, but I would have expected conn.getOutputStream
to return the same object every time, or at least an object that /felt/
like the same object every time. Strange.

> So if I call conn.getOutputStream().close(); 10 times, I get a very
> interesting method name.  I looked at the source for this, and it was
> not apparent that they meant to do this.  However, with this code, my
> method name becomes:
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> POST

Nice.

- -chbris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAknbn9IACgkQ9CaO5/Lv0PDyJACgw9GfbGHvAqUfuaP+vRcNEa0B
2m0An34BtHsiwEZ/G0e0zq7rlbmn8wN4
=Fax0
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Help with a Tomcat issue???

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Jason,

On 4/6/2009 6:33 PM, Jason Smith wrote:
> Sun's implementation of HttpURLConnector apparently creates a new
> ChunkedOutputStream every time you call .getOutputStream().

That's obnoxious and completely unexpected. Latest version of Java, huh?
Too bad. Obviously, the solution is for your client to cache the result
of conn.getOutputStream, but I would have expected conn.getOutputStream
to return the same object every time, or at least an object that /felt/
like the same object every time. Strange.

> So if I call conn.getOutputStream().close(); 10 times, I get a very
> interesting method name.  I looked at the source for this, and it was
> not apparent that they meant to do this.  However, with this code, my
> method name becomes:
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> 0
> 
> POST

Nice.

- -chbris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAknbn9IACgkQ9CaO5/Lv0PDyJACgw9GfbGHvAqUfuaP+vRcNEa0B
2m0An34BtHsiwEZ/G0e0zq7rlbmn8wN4
=Fax0
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
Will do.  

-----Original Message-----
From: Mark Thomas [mailto:markt@apache.org] 
Sent: Tuesday, April 07, 2009 8:15 AM
To: Tomcat Users List
Subject: Re: Help with a Tomcat issue???

Jason Smith wrote:
> As follow-up, I guess I would have to count this as a core Java API bug, since the high-level functions (HttpURLConnection) allow you to routinely emit bad markup.
> 
> However, wouldn't it be prudent in Tomcat to recognize that something has gone wrong with the method name earlier?  Should method names ever be allowed to contain numbers?  How about carriage returns and other white space?  
> 
> So the root question is, should I write this up as a low-priority bug, or is the current behavior desired?

Technically, there is a bug here. When we are reading the request method
   if we see CR or LF then the request is invalid and Tomcat should
return a 400 Bad Request.

If you could write this up in bugzilla that would be great.

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Help with a Tomcat issue???

Posted by Mark Thomas <ma...@apache.org>.
Jason Smith wrote:
> As follow-up, I guess I would have to count this as a core Java API bug, since the high-level functions (HttpURLConnection) allow you to routinely emit bad markup.
> 
> However, wouldn't it be prudent in Tomcat to recognize that something has gone wrong with the method name earlier?  Should method names ever be allowed to contain numbers?  How about carriage returns and other white space?  
> 
> So the root question is, should I write this up as a low-priority bug, or is the current behavior desired?

Technically, there is a bug here. When we are reading the request method
   if we see CR or LF then the request is invalid and Tomcat should
return a 400 Bad Request.

If you could write this up in bugzilla that would be great.

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
As follow-up, I guess I would have to count this as a core Java API bug, since the high-level functions (HttpURLConnection) allow you to routinely emit bad markup.

However, wouldn't it be prudent in Tomcat to recognize that something has gone wrong with the method name earlier?  Should method names ever be allowed to contain numbers?  How about carriage returns and other white space?  

So the root question is, should I write this up as a low-priority bug, or is the current behavior desired?    

-----Original Message-----
From: Mark Thomas [mailto:markt@apache.org] 
Sent: Tuesday, April 07, 2009 2:40 AM
To: Tomcat Users List
Subject: Re: Help with a Tomcat issue???

Jason Smith wrote:
> Solved.  You gave me a clue that helped solve it, though Tomcat could handle this better (not put '0 POST' in for the method name in the first place).  
> 
> Sun's implementation of HttpURLConnector apparently creates a new ChunkedOutputStream every time you call .getOutputStream().  In other words, multiple calls to conn.getOutputStream().close(); cause corrupted output.  Calling .close() on the same output stream does not cause corrupted output.  

Glad you found the problem.

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Help with a Tomcat issue???

Posted by Mark Thomas <ma...@apache.org>.
Jason Smith wrote:
> Solved.  You gave me a clue that helped solve it, though Tomcat could handle this better (not put '0 POST' in for the method name in the first place).  
> 
> Sun's implementation of HttpURLConnector apparently creates a new ChunkedOutputStream every time you call .getOutputStream().  In other words, multiple calls to conn.getOutputStream().close(); cause corrupted output.  Calling .close() on the same output stream does not cause corrupted output.  

Glad you found the problem.

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
Solved.  You gave me a clue that helped solve it, though Tomcat could handle this better (not put '0 POST' in for the method name in the first place).  

Sun's implementation of HttpURLConnector apparently creates a new ChunkedOutputStream every time you call .getOutputStream().  In other words, multiple calls to conn.getOutputStream().close(); cause corrupted output.  Calling .close() on the same output stream does not cause corrupted output.  
            
So if I call conn.getOutputStream().close(); 10 times, I get a very interesting method name.  I looked at the source for this, and it was not apparent that they meant to do this.  However, with this code, my method name becomes:

0

0

0

0

0

0

0

0

0

POST


So this is a case of the client emitting bad HTTP, and me not reading the socket dump correctly.

Thanks for your help!


-----Original Message-----
From: Jason Smith [mailto:jsmith@infotrustgroup.com] 
Sent: Monday, April 06, 2009 1:47 PM
To: Tomcat Users List
Subject: RE: Help with a Tomcat issue???

I'll see if I can set up a working example. And I didn't mean to say "proxy," not that there is one. We aren't using JK connector. :-)

-----Original Message-----
From: Jason Smith [mailto:jsmith@infotrustgroup.com] 
Sent: Monday, April 06, 2009 1:28 PM
To: Tomcat Users List
Subject: RE: Help with a Tomcat issue???

Just Tomcat, no proxy.  

And I agree, that isn't the way you'd want to fix it ultimately, but I was experimenting to find out what worked.  You'd ultimately like to not see the '0' at the beginning of the buffer.  I found the place where it was getting copied to the beginning of the buffer, but I can't figure out the logic behind the code.  Too many micro opts (it's fast!).

What did NOT work was simply subverting the copying of the data and setting the buffer length to 0, as is normally the case.  There are apparently some instances where .nextRequest must copy the data from one buffer to the next.  I tried.  Things didn't work so well after that...  :-)  I mentioned one of those in the previous email.  

But again, I am not yet familiar with this part of the Tomcat code.  So I am probably missing something fairly obvious.



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
I'll see if I can set up a working example. And I didn't mean to say "proxy," not that there is one. We aren't using JK connector. :-)

-----Original Message-----
From: Jason Smith [mailto:jsmith@infotrustgroup.com] 
Sent: Monday, April 06, 2009 1:28 PM
To: Tomcat Users List
Subject: RE: Help with a Tomcat issue???

Just Tomcat, no proxy.  

And I agree, that isn't the way you'd want to fix it ultimately, but I was experimenting to find out what worked.  You'd ultimately like to not see the '0' at the beginning of the buffer.  I found the place where it was getting copied to the beginning of the buffer, but I can't figure out the logic behind the code.  Too many micro opts (it's fast!).

What did NOT work was simply subverting the copying of the data and setting the buffer length to 0, as is normally the case.  There are apparently some instances where .nextRequest must copy the data from one buffer to the next.  I tried.  Things didn't work so well after that...  :-)  I mentioned one of those in the previous email.  

But again, I am not yet familiar with this part of the Tomcat code.  So I am probably missing something fairly obvious.



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Help with a Tomcat issue???

Posted by Jason Smith <js...@infotrustgroup.com>.
Just Tomcat, no proxy.  

And I agree, that isn't the way you'd want to fix it ultimately, but I was experimenting to find out what worked.  You'd ultimately like to not see the '0' at the beginning of the buffer.  I found the place where it was getting copied to the beginning of the buffer, but I can't figure out the logic behind the code.  Too many micro opts (it's fast!).

What did NOT work was simply subverting the copying of the data and setting the buffer length to 0, as is normally the case.  There are apparently some instances where .nextRequest must copy the data from one buffer to the next.  I tried.  Things didn't work so well after that...  :-)  I mentioned one of those in the previous email.  

But again, I am not yet familiar with this part of the Tomcat code.  So I am probably missing something fairly obvious.

-----Original Message-----
From: Mark Thomas [mailto:markt@apache.org] 
Sent: Monday, April 06, 2009 1:18 PM
To: Tomcat Users List
Subject: Re: Help with a Tomcat issue???

Jason Smith wrote:

> I have intercepted the socket InputStream (in Http11BaseProtocol) and looked at the data coming in.  It is what I expect ('POST .').  Yes, let me repeat that, the data coming in from the socket is good.  I've visually inspected it, and it matches the spec.
It isn't just this request that needs to match the spec - the previous
one has to as well. Otherwise when using keep-alive or pipe-lining you
could see the behaviour you are seeing.

> When I get into the InternalInputBuffer, I am seeing there is data left over at the end of one stream ('0\n\n') which gets appended to the beginning of the next request because of the code in .nextRequest().  It almost looks like someone downstream is not consuming the very last byte in the buffer.
Can you provide source code for the simplest possible client and
simplest possible servlet that demonstrates the issue you are seeing?

> But then why the heck does .nextRequest copy it into the new buffer for the next request?  This makes no sense to me.
Off the top of my head - I haven't checked the code - pipe-lining?

> Is this a problem with downstream code, which has a responsibility to consume every byte in the input stream? Or is it bad code in nextRequest(), which really should not be taking the tail of one request and appending it to the next?  Or is it something else?
Broken client or Tomcat bug would be my guess right now.

> Should this be fixed in this method, or is there a better place?
> 
> One quick fix:
> 
> byte chr = 0;
>         do {
> 
>             // Read new bytes if needed
>             if (pos >= lastValid) {
>                 if (!fill())
>                     throw new EOFException(sm.getString("iib.eof.error"));
>             }
> 
>             chr = buf[pos++];
> 
>         } while ((chr == Constants.CR) || (chr == Constants.LF) || (chr == '0'));
> 
> 
> I simply check for the '0' character as well.  This is a bit of a hack, but I don't know the code well enough to know if the leading '0' (which I believe is the last line from a previous chunked POST) is supposed to be there or not.

That almost certainly isn't the way to fix this. That looks to be fixing
 the symptom rather than the root cause.

> Any help would be appreciated.  
> 
> Tomcat 5.5.27, Java 6u13.

Just a double check. Just Tomcat and no httpd/mod_jk/mod_proxy?

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Help with a Tomcat issue???

Posted by Mark Thomas <ma...@apache.org>.
Jason Smith wrote:

> I have intercepted the socket InputStream (in Http11BaseProtocol) and looked at the data coming in.  It is what I expect ('POST .').  Yes, let me repeat that, the data coming in from the socket is good.  I've visually inspected it, and it matches the spec.
It isn't just this request that needs to match the spec - the previous
one has to as well. Otherwise when using keep-alive or pipe-lining you
could see the behaviour you are seeing.

> When I get into the InternalInputBuffer, I am seeing there is data left over at the end of one stream ('0\n\n') which gets appended to the beginning of the next request because of the code in .nextRequest().  It almost looks like someone downstream is not consuming the very last byte in the buffer.
Can you provide source code for the simplest possible client and
simplest possible servlet that demonstrates the issue you are seeing?

> But then why the heck does .nextRequest copy it into the new buffer for the next request?  This makes no sense to me.
Off the top of my head - I haven't checked the code - pipe-lining?

> Is this a problem with downstream code, which has a responsibility to consume every byte in the input stream? Or is it bad code in nextRequest(), which really should not be taking the tail of one request and appending it to the next?  Or is it something else?
Broken client or Tomcat bug would be my guess right now.

> Should this be fixed in this method, or is there a better place?
> 
> One quick fix:
> 
> byte chr = 0;
>         do {
> 
>             // Read new bytes if needed
>             if (pos >= lastValid) {
>                 if (!fill())
>                     throw new EOFException(sm.getString("iib.eof.error"));
>             }
> 
>             chr = buf[pos++];
> 
>         } while ((chr == Constants.CR) || (chr == Constants.LF) || (chr == '0'));
> 
> 
> I simply check for the '0' character as well.  This is a bit of a hack, but I don't know the code well enough to know if the leading '0' (which I believe is the last line from a previous chunked POST) is supposed to be there or not.

That almost certainly isn't the way to fix this. That looks to be fixing
 the symptom rather than the root cause.

> Any help would be appreciated.  
> 
> Tomcat 5.5.27, Java 6u13.

Just a double check. Just Tomcat and no httpd/mod_jk/mod_proxy?

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org