You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Andy Wang <aw...@ptc.com> on 2015/10/19 23:45:43 UTC
Chunked transfer delay with httpd 2.4 + mod_jk 1.2.41 on Windows.
Hi all,
I'm seeing a weird problem that I'm running out of ideas on. I'm going
to send this email to both the apache httpd users list and the tomcat
users list (separate messages) but hoping for any ideas at all.
The issue is currently reproduced using Apache httpd 2.4.16, mod_jk
1.2.41 and tomcat 8.0.28.
I've created a very very simple JSP page that does nothing but print a
small string, but I've tried changing the jsp page to print a very very
large string (10000+ characters) and no difference.
If I POST to this JSP page, and something like mod_deflate is in place
to force a chunked transfer the TCP packet capture looks like this:
No. Time Source Destination Protocol Length Info
1850 4827.762721000 client server TCP 66 54131→2280
[SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
1851 4827.764976000 server client TCP 66 2280→54131
[SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
1852 4827.765053000 client server TCP 54 54131→2280
[ACK] Seq=1 Ack=1 Win=131328 Len=0
1853 4827.765315000 client server HTTP 791 POST
/JSPtoPostTo HTTP/1.1
1854 4827.777981000 server client TCP 466 [TCP
segment of a reassembled PDU]
1855 4827.982961000 client server TCP 54 54131→2280
[ACK] Seq=738 Ack=413 Win=130816 Len=0
1856 4832.770458000 server client HTTP 74 HTTP/1.1
200 OK (text/html)
1857 4832.770459000 server client TCP 60 2280→54131
[FIN, ACK] Seq=433 Ack=738 Win=65536 Len=0
1858 4832.770555000 client server TCP 54 54131→2280
[ACK] Seq=738 Ack=434 Win=130816 Len=0
1859 4832.770904000 client server TCP 54 54131→2280
[FIN, ACK] Seq=738 Ack=434 Win=130816 Len=0
1860 4832.774200000 server client TCP 60 2280→54131
[ACK] Seq=434 Ack=739 Win=65536 Len=0
Spdficially, note the 5 second delay between the first segment (No.
1854) and the second data segment (1856).
The first segment contains the headers, the second segment contains the
mod_deflate compressed contents.
Here's where it gets sort of interesting.
I can only reproduce this with one client. We have a custom NPAPI
plugin that this problem occurs on with all versions of firefox. I
cannot reproduce it with any other client. I've used HttpRequester
extension on firefox to construct an arbitrary POST. I've copied the
raw HTTP request from the wireshark capture:
POST
/Windchill/wtcore/jsp/wvs/mkannio.jsp?CSRF_NONCE=gXFm878tFEjetz6Y6DgPscd5WiSqzlzxuRYjnsx1Igq6hwio7ToBpeV8dgCk9nH95UEEn%2B9IQXXkhgqstENexI0dJ3HohATr8BkqwtAaTiW9hg6puEcum9UfUjqpigM%3D&GetNewASTFile=1&name=test123123123&type=0&path=OR:wt.viewmarkup.DerivedImage:52607&extension=.ast
HTTP/1.1
Host: host:2280
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:41.0) Gecko/20100101
Firefox/41.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate
Cookie: JSESSIONID=F3B0524C87BD94396CCDE40FF837D2F8.tomcat1
Authorization: Basic d2NhZG1pbjp3Y2FkbWlu
Connection: keep-alive
Content-length: 0
Content-Type: text/plain
and used ncat and curl to attempt to simulate the request and no luck
reproducing it.
This does not occur with Apache httpd 2.2.31 and mod_jk 1.2.41. And so
far, it only occurs when the server is on Windows.
I can't come up with any scenario where I can explain how the client
could possibly be the factor.
I've enabled mod_jk's trace logging and according to mod_jk the ajp
request was handled and processed in less than a second.
The timing really seems to imply that this is all somwhere in
mod_deflate. But I've tried something similar by creating an html file
and request it via a POST instead of a GET and the problem doesn't occur
either.
Hoping for any ideas on where to go with this.
Thanks,
Andy
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Chunked transfer delay with httpd 2.4 + mod_jk 1.2.41 on Windows.
Posted by Andy Wang <aw...@ptc.com>.
On 10/19/2015 06:04 PM, Konstantin Kolinko wrote:request.
>
> Is the below a capture between your client and HTTPD? (as opposed to
> one between HTTPD and Tomcat)
>
The capture is between client and httpd
>
> Note that Basic auth sends password in plain text (encoded in base64).
> So you password is written on the above line.
>
Yeah, I know. If you decode it yu'll see it's throwaway credentials :)
>> Connection: keep-alive
>> Content-length: 0
>> Content-Type: text/plain
>
> Content-Length of 0 means that this POST request has no body.
>
Yup. This is just to simulate the issue.
The issue is purely on the response, not on the requestion.
> BTW, a delay of several seconds may be there is a client expects a
> 100-continue response from the server. If there is no HTTP status 100
> response it may proceed sending the body.
There is no 100-continue behavior here.
As i also posted this to the users@httpd mailing list, they've responded
over there. It looks like the pipelining feature is resulting in a
delay before flushing if the payload isn't a full packet size.
So that looks like a likely candidate here.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Chunked transfer delay with httpd 2.4 + mod_jk 1.2.41 on Windows.
Posted by Konstantin Kolinko <kn...@gmail.com>.
2015-10-20 0:45 GMT+03:00 Andy Wang <aw...@ptc.com>:
> Hi all,
> I'm seeing a weird problem that I'm running out of ideas on. I'm going to
> send this email to both the apache httpd users list and the tomcat users
> list (separate messages) but hoping for any ideas at all.
>
> The issue is currently reproduced using Apache httpd 2.4.16, mod_jk 1.2.41
> and tomcat 8.0.28.
>
> I've created a very very simple JSP page that does nothing but print a small
> string, but I've tried changing the jsp page to print a very very large
> string (10000+ characters) and no difference.
>
> If I POST to this JSP page, and something like mod_deflate is in place to
> force a chunked transfer the TCP packet capture looks like this:
mod_deflate may use chunked transfer to deliver _response_, but it
does not influence how you client is sending a request.
Is the below a capture between your client and HTTPD? (as opposed to
one between HTTPD and Tomcat)
> No. Time Source Destination Protocol Length Info
> 1850 4827.762721000 client server TCP 66 54131→2280
> [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
> 1851 4827.764976000 server client TCP 66 2280→54131
> [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
> 1852 4827.765053000 client server TCP 54 54131→2280
> [ACK] Seq=1 Ack=1 Win=131328 Len=0
> 1853 4827.765315000 client server HTTP 791 POST
> /JSPtoPostTo HTTP/1.1
> 1854 4827.777981000 server client TCP 466 [TCP segment of
> a reassembled PDU]
> 1855 4827.982961000 client server TCP 54 54131→2280
> [ACK] Seq=738 Ack=413 Win=130816 Len=0
> 1856 4832.770458000 server client HTTP 74 HTTP/1.1 200 OK
> (text/html)
> 1857 4832.770459000 server client TCP 60 2280→54131
> [FIN, ACK] Seq=433 Ack=738 Win=65536 Len=0
> 1858 4832.770555000 client server TCP 54 54131→2280
> [ACK] Seq=738 Ack=434 Win=130816 Len=0
> 1859 4832.770904000 client server TCP 54 54131→2280
> [FIN, ACK] Seq=738 Ack=434 Win=130816 Len=0
> 1860 4832.774200000 server client TCP 60 2280→54131
> [ACK] Seq=434 Ack=739 Win=65536 Len=0
>
> Spdficially, note the 5 second delay between the first segment (No. 1854)
> and the second data segment (1856).
> The first segment contains the headers, the second segment contains the
> mod_deflate compressed contents.
>
> Here's where it gets sort of interesting.
> I can only reproduce this with one client. We have a custom NPAPI plugin
> that this problem occurs on with all versions of firefox. I cannot
> reproduce it with any other client. I've used HttpRequester extension on
> firefox to construct an arbitrary POST. I've copied the raw HTTP request
> from the wireshark capture:
>
> POST
> /Windchill/wtcore/jsp/wvs/mkannio.jsp?CSRF_NONCE=gXFm878tFEjetz6Y6DgPscd5WiSqzlzxuRYjnsx1Igq6hwio7ToBpeV8dgCk9nH95UEEn%2B9IQXXkhgqstENexI0dJ3HohATr8BkqwtAaTiW9hg6puEcum9UfUjqpigM%3D&GetNewASTFile=1&name=test123123123&type=0&path=OR:wt.viewmarkup.DerivedImage:52607&extension=.ast
> HTTP/1.1
> Host: host:2280
> User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:41.0) Gecko/20100101
> Firefox/41.0
> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
> Accept-Language: en-US,en;q=0.5
> Accept-Encoding: gzip, deflate
> Cookie: JSESSIONID=F3B0524C87BD94396CCDE40FF837D2F8.tomcat1
> Authorization: Basic d2NhZG1pbjp3Y2FkbWlu
Note that Basic auth sends password in plain text (encoded in base64).
So you password is written on the above line.
> Connection: keep-alive
> Content-length: 0
> Content-Type: text/plain
Content-Length of 0 means that this POST request has no body.
> and used ncat and curl to attempt to simulate the request and no luck
> reproducing it.
>
> This does not occur with Apache httpd 2.2.31 and mod_jk 1.2.41. And so far,
> it only occurs when the server is on Windows.
>
> I can't come up with any scenario where I can explain how the client could
> possibly be the factor.
>
> I've enabled mod_jk's trace logging and according to mod_jk the ajp request
> was handled and processed in less than a second.
>
> The timing really seems to imply that this is all somwhere in mod_deflate.
> But I've tried something similar by creating an html file and request it via
> a POST instead of a GET and the problem doesn't occur either.
BTW, a delay of several seconds may be there is a client expects a
100-continue response from the server. If there is no HTTP status 100
response it may proceed sending the body.
http://tools.ietf.org/html/rfc7231#section-5.1.1
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Chunked transfer delay with httpd 2.4 + mod_jk 1.2.41 on Windows.
Posted by Andy Wang <aw...@ptc.com>.
I should add that we have a custom CompressionFilter that also
reproduces the problem without mod_deflate. Which seems to point to
something in Apache httpd and chunked transfers being the hold up, but I
don't know for sure.
I'm currently exclusively testing with mod_deflate as this is OOTB
behavior rather than introduce the confusion of a custom ServletFilter.
Andy
On 10/19/2015 04:45 PM, Andy Wang wrote:
> Hi all,
> I'm seeing a weird problem that I'm running out of ideas on. I'm going
> to send this email to both the apache httpd users list and the tomcat
> users list (separate messages) but hoping for any ideas at all.
>
> The issue is currently reproduced using Apache httpd 2.4.16, mod_jk
> 1.2.41 and tomcat 8.0.28.
>
> I've created a very very simple JSP page that does nothing but print a
> small string, but I've tried changing the jsp page to print a very very
> large string (10000+ characters) and no difference.
>
> If I POST to this JSP page, and something like mod_deflate is in place
> to force a chunked transfer the TCP packet capture looks like this:
>
> No. Time Source Destination Protocol Length Info
> 1850 4827.762721000 client server TCP 66 54131→2280
> [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
> 1851 4827.764976000 server client TCP 66 2280→54131
> [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1
> 1852 4827.765053000 client server TCP 54 54131→2280
> [ACK] Seq=1 Ack=1 Win=131328 Len=0
> 1853 4827.765315000 client server HTTP 791 POST
> /JSPtoPostTo HTTP/1.1
> 1854 4827.777981000 server client TCP 466 [TCP
> segment of a reassembled PDU]
> 1855 4827.982961000 client server TCP 54 54131→2280
> [ACK] Seq=738 Ack=413 Win=130816 Len=0
> 1856 4832.770458000 server client HTTP 74 HTTP/1.1
> 200 OK (text/html)
> 1857 4832.770459000 server client TCP 60 2280→54131
> [FIN, ACK] Seq=433 Ack=738 Win=65536 Len=0
> 1858 4832.770555000 client server TCP 54 54131→2280
> [ACK] Seq=738 Ack=434 Win=130816 Len=0
> 1859 4832.770904000 client server TCP 54 54131→2280
> [FIN, ACK] Seq=738 Ack=434 Win=130816 Len=0
> 1860 4832.774200000 server client TCP 60 2280→54131
> [ACK] Seq=434 Ack=739 Win=65536 Len=0
>
> Spdficially, note the 5 second delay between the first segment (No.
> 1854) and the second data segment (1856).
> The first segment contains the headers, the second segment contains the
> mod_deflate compressed contents.
>
> Here's where it gets sort of interesting.
> I can only reproduce this with one client. We have a custom NPAPI
> plugin that this problem occurs on with all versions of firefox. I
> cannot reproduce it with any other client. I've used HttpRequester
> extension on firefox to construct an arbitrary POST. I've copied the
> raw HTTP request from the wireshark capture:
>
> POST
> /Windchill/wtcore/jsp/wvs/mkannio.jsp?CSRF_NONCE=gXFm878tFEjetz6Y6DgPscd5WiSqzlzxuRYjnsx1Igq6hwio7ToBpeV8dgCk9nH95UEEn%2B9IQXXkhgqstENexI0dJ3HohATr8BkqwtAaTiW9hg6puEcum9UfUjqpigM%3D&GetNewASTFile=1&name=test123123123&type=0&path=OR:wt.viewmarkup.DerivedImage:52607&extension=.ast
> HTTP/1.1
> Host: host:2280
> User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:41.0) Gecko/20100101
> Firefox/41.0
> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
> Accept-Language: en-US,en;q=0.5
> Accept-Encoding: gzip, deflate
> Cookie: JSESSIONID=F3B0524C87BD94396CCDE40FF837D2F8.tomcat1
> Authorization: Basic d2NhZG1pbjp3Y2FkbWlu
> Connection: keep-alive
> Content-length: 0
> Content-Type: text/plain
>
> and used ncat and curl to attempt to simulate the request and no luck
> reproducing it.
>
> This does not occur with Apache httpd 2.2.31 and mod_jk 1.2.41. And so
> far, it only occurs when the server is on Windows.
>
> I can't come up with any scenario where I can explain how the client
> could possibly be the factor.
>
> I've enabled mod_jk's trace logging and according to mod_jk the ajp
> request was handled and processed in less than a second.
>
> The timing really seems to imply that this is all somwhere in
> mod_deflate. But I've tried something similar by creating an html file
> and request it via a POST instead of a GET and the problem doesn't occur
> either.
>
> Hoping for any ideas on where to go with this.
>
> Thanks,
> Andy
>
> ---------------------------------------------------------------------
> 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