Bug 38014

Summary: [PatchAvailable] The status '100 Continue' will be sent after the final status code
Product: Apache httpd-2 Reporter: keilh <hartmut.keil>
Component: CoreAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED FIXED    
Severity: normal CC: basant.kukreja
Priority: P2 Keywords: PatchAvailable
Version: 2.2-HEAD   
Target Milestone: ---   
Hardware: Other   
OS: other   
Attachments: [PATCH 38014]
Revised patch

Description keilh 2005-12-22 21:02:15 UTC
In the case of keepalive the request body will be discared in 
'ap_discard_request_body(..)'. 

By that the status line  'HTTP/1.1 100 Continue' will be sent 
after the final status code if the body has not been consumed 
until now:

=>[1] ssl_filter_write(f = 0x254300, data = 0x25f260 "HTTP/1.1 100
Continue^M\n^M\n", len = 25U), line 765 in "ssl_engine_io.c"
  [2] ssl_io_filter_output(f = 0x254300, bb = 0x25f280), line 1438 in
"ssl_engine_io.c"
  [3] ap_pass_brigade(next = 0x254300, bb = 0x25f280), line 526 in "util_filter.c"
  [4] ap_http_filter(f = 0x25edd8, b = 0x25f220, mode = AP_MODE_READBYTES, block
= APR_BLOCK_READ, readbytes = 8192LL), line 201 in "http_filters.c"
  [5] ap_get_brigade(next = 0x25edd8, bb = 0x25f220, mode = AP_MODE_READBYTES,
block = APR_BLOCK_READ, readbytes = 8192LL), line 490 in "util_filter.c"
  [6] ap_discard_request_body(r = 0x25ddc0), line 1092 in "http_filters.c"
  [7] ap_finalize_request_protocol(r = 0x25ddc0), line 1119 in "protocol.c"
  [8] ap_process_request(r = 0x25ddc0), line 268 in "http_request.c"
  
So the client is reading 'HTTP/1.1 100 Continue' as response for its next
request that may does not contain the 'Expect: 100-continue' header.
That is violating the spec.

Another point is that it makes no sense to possibly *invite* the client 
for sending the body just to discard it.

The fix is quite small, see the following patch:

Index: server/protocol.c
===================================================================
RCS file:
/opt/projects/CVSROOT/navajo/src/org/apache/httpd-2.2.X/server/protocol.c,v
retrieving revision 1.1
diff -c -r1.1 protocol.c
*** server/protocol.c   2005/12/08 14:51:37     1.1
--- server/protocol.c   2005/12/22 19:14:56
***************
*** 1116,1122 ****
   */
  AP_DECLARE(void) ap_finalize_request_protocol(request_rec *r)
  {
!     (void) ap_discard_request_body(r);

      /* tell the filter chain there is no more content coming */
      if (!r->eos_sent) {
--- 1116,1129 ----
   */
  AP_DECLARE(void) ap_finalize_request_protocol(request_rec *r)
  {
!       /* Avoid sending 'HTTP/1.1 100 Continue' after the response.
!          If the client is waiting for 'HTTP/1.1 100 Continue' before
!          sending the body, the body has been already sent, or will never be.
!          (see rfc 2616 section 8.2.3)
!       */
!       r->expecting_100 = 0;
!
!       (void) ap_discard_request_body(r);

      /* tell the filter chain there is no more content coming */
      if (!r->eos_sent) {
Comment 1 Joe Orton 2005-12-22 23:56:01 UTC
Can you give an example configuration and request which triggers this?
Comment 2 keilh 2006-01-03 16:04:45 UTC
The described behaviour can be reproduced with the following configuration

<Location /asis>
SetHandler send-as-is
</Location>


The request 

GET /asis/index.html HTTP/1.1
Host: some.server.com
Expect: 100-continue
Content-Length: 10

will get the response:

HTTP/1.1 200 OK
Date: Tue, 03 Jan 2006 14:39:54 GMT
Server: Apache/2.2.0 (Unix) mod_ssl/2.2.0 OpenSSL/0.9.7g
Some-Special-Header: never-mind
Content-Length: 11
Content-Type: text/plain

Some data

HTTP/1.1 100 Continue


As described the 'HTTP/1.1 100 Continue' will be sent in 
ap_finalize_request_protocol(..) (see stack above)



Comment 3 Basant Kumar Kukreja 2007-02-02 11:30:12 UTC
<pre>
Bug also reproduces with mod_perl.

For a simple test script test.pl
#!/usr/bin/perl
print "Content-type: text/plain\n\n";
print "mod_perl 2.0 rocks!\n";

If the request contains :
GET /perl/test.pl HTTP/1.1
Host: myhost.domain
Content-Length: 3
Expect: 100-continue

abc

The output is :
HTTP/1.1 200 OK
Date: Fri, 02 Feb 2007 19:17:04 GMT
Server: Apache/2.2.5-dev (Unix) mod_perl/2.0.4-dev Perl/v5.8.8
Transfer-Encoding: chunked
Content-Type: text/plain

14
mod_perl 2.0 rocks!

HTTP/1.1 100 Continue

0

--------------------------------------
Note that "HTTP/1.1 100 Continue" is printed after the response.

httpd.conf contains :
LoadModule perl_module modules/mod_perl.so
Alias /perl/ /disk/apache/apache2/perl/
<Location /perl/>
  SetHandler perl-script
  PerlResponseHandler ModPerl::Registry
  PerlOptions +ParseHeaders
  Options +ExecCGI
  Order allow,deny
  Allow from all 
</Location>
--------------------------------------

However if the request is /index.html then the apache behavior is correct.
GET /index.html HTTP/1.1
Host: myhost.domain
Content-Length: 3
Expect: 100-continue

abc


-----
Response
-----

HTTP/1.1 100 Continue
HTTP/1.1 200 OK
Date: Fri, 02 Feb 2007 19:23:03 GMT
Server: Apache/2.2.5-dev (Unix) mod_perl/2.0.4-dev Perl/v5.8.8
Last-Modified: Fri, 26 Jan 2007 21:40:07 GMT
ETag: "7008b-2c-5f0e7bc0"
Accept-Ranges: bytes
Content-Length: 44
Content-Type: text/html

<html><body><h1>It works!</h1></body></html>

</pre>
Comment 4 Basant Kumar Kukreja 2007-02-05 14:07:53 UTC
Comments for Suggested fix:
(a) Setting expecting_100 to 0 is not appropriate because use of expecting_100
flag in request_rec is to find out if user is expecting 100 response code.
(b) With the suggested fix, HEAD response is also affected.
For a request : 
HEAD /asis/index.asis HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc


The output without the fix is :
HTTP/1.1 100 Continue
HTTP/1.1 200 OK
Date: Mon, 05 Feb 2007 21:55:55 GMT
Server: Apache/2.2.5-dev (Unix) mod_perl/2.0.4-dev Perl/v5.8.8
Content-Type: arbit

After the fix, 100 Continue line is omitted :
HTTP/1.1 200 OK
Date: Mon, 05 Feb 2007 21:54:46 GMT
Server: Apache/2.2.5-dev (Unix) mod_perl/2.0.4-dev Perl/v5.8.8
Content-Type: arbit
Comment 5 Basant Kumar Kukreja 2007-02-06 12:36:18 UTC
Created attachment 19532 [details]
[PATCH 38014]

If client send "Expect: 100-Continue" request then ap_http_filter prepares
"HTTP/1.1 100 Continue" and appends a brigade. The issue is that modules may
already have started sending the headers/response. If it is so then 100
Continue is sent after the response. In this fix "100 Continue" line is added
only if eos_sent is 0 and send_bytes is 0. Unfortunately there is no field in
request_rec, I found which states that response status is already sent.


The patch have been tested with following situation.

(a) testing with mod_perl
GET /perl/test.pl HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc

(b) testing with home url.

GET /index.html HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc

(c) testing with redirect
GET /redir HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc

(d) testing with mod_asis as reported by bug
HEAD /asis/index.asis HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc


(e) testing with HEAD request
GET /asis/index.asis HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc


(f) testing with a perl script which doesn't generate any output
GET /perl/test1.pl HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc

(g) HEAD request for /index.html
HEAD /index.html HTTP/1.1
Host: lbasantk3.red.iplanet.com
Content-Length: 3
Expect: 100-continue

abc
Comment 6 Basant Kumar Kukreja 2007-02-08 16:42:49 UTC
Marking the status line as PatchAvailable
Comment 7 William A. Rowe Jr. 2007-02-27 17:49:46 UTC
  !(f->r->eos_sent || f->r->bytes_sent) 

appears slightly more efficient, but in, principle +1.
Comment 8 Basant Kumar Kukreja 2007-02-28 13:26:10 UTC
Created attachment 19652 [details]
Revised patch

Revised patch after incorporating optimization suggestion by wrowe.
Comment 9 Nick Kew 2007-09-10 06:20:46 UTC
Patch committed to trunk in r574240.
Comment 10 Nick Kew 2007-09-12 06:31:36 UTC
Fixed in trunk in r574950.
Comment 11 Ruediger Pluem 2007-09-26 13:32:10 UTC
Backported to 2.2.x in r574950.