Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 17 May 2013, at 11:26 AM, Ruediger Pluem rpl...@apache.org wrote: We should not see an EOS bucket before inflate(ctx-stream, Z_NO_FLUSH); in line 1061 returned Z_STREAM_END. This would mean we received an incomplete compressed stream. And if we see Z_STREAM_END we leave the for loop and stop processing buckets. Hence we cannot hit a possible EOS bucket in the brigade any longer. So the test possibly sents an incomplete compressed body. Further investigation showed mod_deflate making some wild assumptions as to the structure of the brigades it received. While deflate correctly detected a truncated body, deflate broke if an EOS bucket followed directly behind the last compressed bucket, which is a valid combination. Fixed in r1484832. Regards, Graham --
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
Here are the 3 patches attached as files (without spurious line breakage). Regards, Yann. On Fri, May 17, 2013 at 7:27 PM, Yann Ylavic ylavic@gmail.com wrote: I am currently working in frontporting some patches I use for a while in the 2.2.x branch and I'd like to propose for trunk (at least, my goal is to upgrade to 2.4 of course). The reason I talk about this in this thread is that 2 of these patches may collide with your current work/review on ap_http_filter() and maybe it worth taking my suggestions into account. If I should open a different thread let me know... My 2 patches serve the following purposes : 1. make mod_proxy_http handle a truncated response body (closed connection with remaining data) like any other streaming error, 2. make LimitRequestBody also apply to mod_proxy_http forwarded requests, 3. make mod_proxy_http respond the HTTP error mapping the ap_http_filter() status. 1. When ap_http_filter() returns APR_EOF, currently mod_proxy simply stops forwarding the response, no log, no error bucket, like a normal end of sream. For an output filter there is no way to be aware of the problem, and mod_cache (for example) will cache an incomplete entity. The following patch addresses this issue : patch1 Index: modules/http/http_filters.c === --- modules/http/http_filters.c(revision 1483799) +++ modules/http/http_filters.c(working copy) @@ -520,8 +524,12 @@ apr_status_t ap_http_filter(ap_filter_t *f, apr_bu ctx-remaining -= totalread; if (ctx-remaining 0) { e = APR_BRIGADE_LAST(b); -if (APR_BUCKET_IS_EOS(e)) -return APR_EOF; +if (APR_BUCKET_IS_EOS(e)) { +apr_bucket_delete(e); +if (APR_BRIGADE_EMPTY(b)) { +return APR_EOF; +} +} } } Index: modules/proxy/mod_proxy_http.c === --- modules/proxy/mod_proxy_http.c(revision 1483799) +++ modules/proxy/mod_proxy_http.c(working copy) @@ -1679,9 +1679,6 @@ int ap_proxy_http_process_response(apr_pool_t * p, mode = APR_BLOCK_READ; continue; } -else if (rv == APR_EOF) { -break; -} else if (rv != APR_SUCCESS) { if (rv == APR_ENOSPC) { ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(02475) @@ -1691,6 +1688,10 @@ int ap_proxy_http_process_response(apr_pool_t * p, ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(02476) Response Transfer-Encoding was not recognised); } +else if (rv == APR_EOF) { +ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO() + Response content is incomplete); +} else { ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(01110) Network error reading response); /patch1 In the 2.2 version of the patch I used APR_INCOMPLETE instead of APR_EOF and change APR_EOF to APR_INCOMPLETE in ap_http_filter() whenever the content is incomplete. I didn't want to change the meaning of APR_EOF in mod_proxy, but now I think mod_proxy has to be fixed and other modules should not be impacted. Note the patch will not trigger APR_EOF on the first call if some data is available with the EOS, IMHO anything received should be forwarded to the client/output filters before closing the stream. 2. LimitRequestBody handling is disabled when mod_proxy is on stage, not only for PROXYREQ_RESPONSE (although the associated comment says does not apply to proxied responses). Maybe there should be a ProxyLimitRequestBody (and ProxyLimitResponseBody?) for the mod_proxy case, not to break some existing configurations (for example with a weird global LimitRequestBody that currently only apply to non-proxy vhosts), but that would duplicate the ap_http_filter() code somewhere else... patch3 Index: modules/http/http_filters.c === --- modules/http/http_filters.c(revision 1483799) +++ modules/http/http_filters.c(working copy) @@ -223,7 +223,7 @@ apr_status_t ap_http_filter(ap_filter_t *f, apr_bu * Would adding a directive to limit the size of proxied * responses be useful? */ -if (!f-r-proxyreq) { +if (f-r-proxyreq != PROXYREQ_RESPONSE) { ctx-limit = ap_get_limit_req_body(f-r); } else { @@ -387,6
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
Graham Leggett wrote: On 15 May 2013, at 9:23 PM, Ruediger Pluem rpl...@apache.org wrote: Now we have: t/apache/pr17629.t (Wstat: 0 Tests: 4 Failed: 1) Failed test: 4 Looking at a verbose version of this test, we see this: # expected: begin-foobar-end # received: !DOCTYPE HTML PUBLIC -//IETF//DTD HTML 2.0//EN # htmlhead # title400 Bad Request/title # /headbody # h1Bad Request/h1 # pYour browser sent a request that this server could not understand.br / # /p # /body/html not ok 4 Tracing through the code, we get a bad request because we trip over this code in mod_deflate: /* If we actually see the EOS, that means we screwed up! */ if (APR_BUCKET_IS_EOS(bkt)) { inflateEnd(ctx-stream); ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, APLOGNO(01390) Encountered EOS bucket in inflate filter (bug?)); return APR_EGENERAL; } Why does seeing an EOS in the input stream mean we screwed up? I don't follow. We should not see an EOS bucket before inflate(ctx-stream, Z_NO_FLUSH); in line 1061 returned Z_STREAM_END. This would mean we received an incomplete compressed stream. And if we see Z_STREAM_END we leave the for loop and stop processing buckets. Hence we cannot hit a possible EOS bucket in the brigade any longer. So the test possibly sents an incomplete compressed body. Regards Rüdiger
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 17 May 2013, at 10:26, Ruediger Pluem rpl...@apache.org wrote: We should not see an EOS bucket before inflate(ctx-stream, Z_NO_FLUSH); in line 1061 returned Z_STREAM_END. This would mean we received an incomplete compressed stream. And if we see Z_STREAM_END we leave the for loop and stop processing buckets. Hence we cannot hit a possible EOS bucket in the brigade any longer. So the test possibly sents an incomplete compressed body. I tried to get my head around the ap_http_filter, it contains way too many 'if special case do special stuff' statements, particularly around the sending of eos buckets, I suspect one of those might be tripping it up. It looks like some simplifying could eliminate an apr_brigade_flatten and another 40-ish bytes per request, will take a look. Regards, Graham --
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
I am currently working in frontporting some patches I use for a while in the 2.2.x branch and I'd like to propose for trunk (at least, my goal is to upgrade to 2.4 of course). The reason I talk about this in this thread is that 2 of these patches may collide with your current work/review on ap_http_filter() and maybe it worth taking my suggestions into account. If I should open a different thread let me know... My 2 patches serve the following purposes : 1. make mod_proxy_http handle a truncated response body (closed connection with remaining data) like any other streaming error, 2. make LimitRequestBody also apply to mod_proxy_http forwarded requests, 3. make mod_proxy_http respond the HTTP error mapping the ap_http_filter() status. 1. When ap_http_filter() returns APR_EOF, currently mod_proxy simply stops forwarding the response, no log, no error bucket, like a normal end of sream. For an output filter there is no way to be aware of the problem, and mod_cache (for example) will cache an incomplete entity. The following patch addresses this issue : patch1 Index: modules/http/http_filters.c === --- modules/http/http_filters.c(revision 1483799) +++ modules/http/http_filters.c(working copy) @@ -520,8 +524,12 @@ apr_status_t ap_http_filter(ap_filter_t *f, apr_bu ctx-remaining -= totalread; if (ctx-remaining 0) { e = APR_BRIGADE_LAST(b); -if (APR_BUCKET_IS_EOS(e)) -return APR_EOF; +if (APR_BUCKET_IS_EOS(e)) { +apr_bucket_delete(e); +if (APR_BRIGADE_EMPTY(b)) { +return APR_EOF; +} +} } } Index: modules/proxy/mod_proxy_http.c === --- modules/proxy/mod_proxy_http.c(revision 1483799) +++ modules/proxy/mod_proxy_http.c(working copy) @@ -1679,9 +1679,6 @@ int ap_proxy_http_process_response(apr_pool_t * p, mode = APR_BLOCK_READ; continue; } -else if (rv == APR_EOF) { -break; -} else if (rv != APR_SUCCESS) { if (rv == APR_ENOSPC) { ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(02475) @@ -1691,6 +1688,10 @@ int ap_proxy_http_process_response(apr_pool_t * p, ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(02476) Response Transfer-Encoding was not recognised); } +else if (rv == APR_EOF) { +ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO() + Response content is incomplete); +} else { ap_log_rerror(APLOG_MARK, APLOG_ERR, rv, r, APLOGNO(01110) Network error reading response); /patch1 In the 2.2 version of the patch I used APR_INCOMPLETE instead of APR_EOF and change APR_EOF to APR_INCOMPLETE in ap_http_filter() whenever the content is incomplete. I didn't want to change the meaning of APR_EOF in mod_proxy, but now I think mod_proxy has to be fixed and other modules should not be impacted. Note the patch will not trigger APR_EOF on the first call if some data is available with the EOS, IMHO anything received should be forwarded to the client/output filters before closing the stream. 2. LimitRequestBody handling is disabled when mod_proxy is on stage, not only for PROXYREQ_RESPONSE (although the associated comment says does not apply to proxied responses). Maybe there should be a ProxyLimitRequestBody (and ProxyLimitResponseBody?) for the mod_proxy case, not to break some existing configurations (for example with a weird global LimitRequestBody that currently only apply to non-proxy vhosts), but that would duplicate the ap_http_filter() code somewhere else... patch3 Index: modules/http/http_filters.c === --- modules/http/http_filters.c(revision 1483799) +++ modules/http/http_filters.c(working copy) @@ -223,7 +223,7 @@ apr_status_t ap_http_filter(ap_filter_t *f, apr_bu * Would adding a directive to limit the size of proxied * responses be useful? */ -if (!f-r-proxyreq) { +if (f-r-proxyreq != PROXYREQ_RESPONSE) { ctx-limit = ap_get_limit_req_body(f-r); } else { @@ -387,6 +387,10 @@ apr_status_t ap_http_filter(ap_filter_t *f, apr_bu } } } +else if (ctx-limit ctx-limit ctx-limit_used) { +/* The limit is already reached, don't read any further. */ +return APR_ENOSPC; +} else {
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 15 May 2013, at 9:23 PM, Ruediger Pluem rpl...@apache.org wrote: Now we have: t/apache/pr17629.t (Wstat: 0 Tests: 4 Failed: 1) Failed test: 4 Looking at a verbose version of this test, we see this: # expected: begin-foobar-end # received: !DOCTYPE HTML PUBLIC -//IETF//DTD HTML 2.0//EN # htmlhead # title400 Bad Request/title # /headbody # h1Bad Request/h1 # pYour browser sent a request that this server could not understand.br / # /p # /body/html not ok 4 Tracing through the code, we get a bad request because we trip over this code in mod_deflate: /* If we actually see the EOS, that means we screwed up! */ if (APR_BUCKET_IS_EOS(bkt)) { inflateEnd(ctx-stream); ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, APLOGNO(01390) Encountered EOS bucket in inflate filter (bug?)); return APR_EGENERAL; } Why does seeing an EOS in the input stream mean we screwed up? I don't follow. Regards, Graham --
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 05/14/2013 08:58 PM, minf...@apache.org wrote: Author: minfrin Date: Tue May 14 18:58:06 2013 New Revision: 1482522 URL: http://svn.apache.org/r1482522 Log: core: Stop the HTTP_IN filter from attempting to write error buckets to the output filters, which is bogus in the proxy case. Create a clean mapping from APR codes to HTTP status codes, and use it where needed. Modified: httpd/httpd/trunk/CHANGES httpd/httpd/trunk/docs/log-message-tags/next-number httpd/httpd/trunk/include/ap_mmn.h httpd/httpd/trunk/include/http_protocol.h httpd/httpd/trunk/modules/dav/main/mod_dav.c httpd/httpd/trunk/modules/generators/mod_cgi.c httpd/httpd/trunk/modules/generators/mod_cgid.c httpd/httpd/trunk/modules/http/http_filters.c httpd/httpd/trunk/modules/proxy/mod_proxy.h httpd/httpd/trunk/modules/proxy/mod_proxy_http.c httpd/httpd/trunk/modules/proxy/proxy_util.c httpd/httpd/trunk/server/util.c This causes new errors / regressions in the test suite. Failed Test Stat Wstat Total Fail Failed List of Failed --- t/apache/chunkinput.t 92 22.22% 7 9 t/apache/contentlength.t 203 15.00% 2 14 18 Regards Rüdiger
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 15 May 2013, at 9:48 AM, Plüm, Rüdiger, Vodafone Group ruediger.pl...@vodafone.com wrote: This causes new errors / regressions in the test suite. Failed Test Stat Wstat Total Fail Failed List of Failed --- t/apache/chunkinput.t 92 22.22% 7 9 t/apache/contentlength.t 203 15.00% 2 14 18 Would it be possible to send a verbose output of these tests? The test suite has segfaulted for me since the proxy mutex bug. Regards, Graham --
RE: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
-Original Message- From: Graham Leggett [mailto:minf...@sharp.fm] Sent: Mittwoch, 15. Mai 2013 10:59 To: dev@httpd.apache.org Subject: Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log- message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/ On 15 May 2013, at 9:48 AM, Plüm, Rüdiger, Vodafone Group ruediger.pl...@vodafone.com wrote: This causes new errors / regressions in the test suite. Failed Test Stat Wstat Total Fail Failed List of Failed -- - t/apache/chunkinput.t 92 22.22% 7 9 t/apache/contentlength.t 203 15.00% 2 14 18 Would it be possible to send a verbose output of these tests? The test suite has segfaulted for me since the proxy mutex bug. /home/pluem/apache/apache_trunk/bin/httpd -d /home/pluem/apache/perl-framework/t -f /home/pluem/apache/perl-framework/t/conf/httpd.conf -D APACHE2 -D PERL_USEITHREADS using Apache/2.5.0-dev (worker MPM) waiting 60 seconds for server to start: ... waiting 60 seconds for server to start: ok (waited 1 secs) server localhost.localdomain:8529 started server localhost.localdomain:8530 listening (mod_nntp_like) server localhost.localdomain:8531 listening (mod_nntp_like_ssl) server localhost.localdomain:8532 listening (mod_ssl) server localhost.localdomain:8533 listening (ssl_optional_cc) server localhost.localdomain:8534 listening (ssl_pr33791) server localhost.localdomain:8535 listening (mod_cache) server localhost.localdomain:8536 listening (mod_include) server localhost.localdomain:8537 listening (proxy_http_reverse) server localhost.localdomain:8538 listening (cve_2011_3368) server localhost.localdomain:8539 listening (mod_headers) server localhost.localdomain:8540 listening (mod_echo) server localhost.localdomain:8541 listening (mod_echo_ssl) server localhost.localdomain:8542 listening (error_document) server localhost.localdomain:8543 listening (http_strict) server localhost.localdomain:8544 listening (mod_proxy) server localhost.localdomain:8545 listening (proxy_http_bal1) server localhost.localdomain:8546 listening (proxy_http_bal2) server localhost.localdomain:8547 listening (proxy_http_balancer) server localhost.localdomain:8548 listening (mod_vhost_alias) server localhost.localdomain:8549 listening (proxy_http_https) server localhost.localdomain:8550 listening (proxy_https_https) server localhost.localdomain:8551 listening (proxy_https_http) t/apache/chunkinput1..9 # Running under perl version 5.008008 for linux # Current time local: Wed May 15 11:03:54 2013 # Current time GMT: Wed May 15 09:03:54 2013 # Using Test.pm version 1.25 # Using Apache/Test.pm version 1.38 testing default ok 1 # testing : response codes # expected: HTTP/1.1 200 OK # received: HTTP/1.1 200 OK ok 2 # testing : trailer (pid) # expected: 15874 # received: 15874 ok 3 ok 4 # testing : response codes # expected: HTTP/1.1 404 Not Found # received: HTTP/1.1 404 Not Found ok 5 ok 6 # testing : response codes # expected: HTTP/1.1 413 Request Entity Too Large # received: HTTP/1.1 200 OK not ok 7 ok 8 # testing : response codes # expected: HTTP/1.1 413 Request Entity Too Large # received: HTTP/1.1 400 Bad Request not ok 9 FAILED tests 7, 9 Failed 2/9 tests, 77.78% okay Failed Test Stat Wstat Total Fail Failed List of Failed --- t/apache/chunkinput.t92 22.22% 7 9 Failed 1/1 test scripts, 0.00% okay. 2/9 subtests failed, 77.78% okay. /home/pluem/apache/apache_trunk/bin/httpd -d /home/pluem/apache/perl-framework/t -f /home/pluem/apache/perl-framework/t/conf/httpd.conf -D APACHE2 -D PERL_USEITHREADS using Apache/2.5.0-dev (worker MPM) waiting 60 seconds for server to start: .. waiting 60 seconds for server to start: ok (waited 1 secs) server localhost.localdomain:8529 started server localhost.localdomain:8530 listening (mod_nntp_like) server localhost.localdomain:8531 listening (mod_nntp_like_ssl) server localhost.localdomain:8532 listening (mod_ssl) server localhost.localdomain:8533 listening (ssl_optional_cc) server localhost.localdomain:8534 listening (ssl_pr33791) server localhost.localdomain:8535 listening (mod_cache) server localhost.localdomain:8536 listening (mod_include) server localhost.localdomain:8537 listening (proxy_http_reverse) server localhost.localdomain:8538 listening (cve_2011_3368) server localhost.localdomain:8539 listening (mod_headers) server localhost.localdomain:8540 listening (mod_echo) server localhost.localdomain:8541 listening (mod_echo_ssl) server localhost.localdomain:8542 listening (error_document) server localhost.localdomain:8543 listening (http_strict) server localhost.localdomain:8544 listening (mod_proxy) server localhost.localdomain:8545 listening (proxy_http_bal1) server localhost.localdomain
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 15 May 2013, at 11:05 AM, Plüm, Rüdiger, Vodafone Group ruediger.pl...@vodafone.com wrote: # testing : response codes # expected: HTTP/1.1 413 Request Entity Too Large # received: HTTP/1.1 200 OK not ok 7 Found further cases where error messages were being ignored, fixed in r1482918. Regards, Graham --
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
Graham Leggett wrote: On 15 May 2013, at 11:05 AM, Plüm, Rüdiger, Vodafone Group ruediger.pl...@vodafone.com wrote: # testing : response codes # expected: HTTP/1.1 413 Request Entity Too Large # received: HTTP/1.1 200 OK not ok 7 Found further cases where error messages were being ignored, fixed in r1482918. Now we have: t/apache/pr17629.t (Wstat: 0 Tests: 4 Failed: 1) Failed test: 4 t/apache/pr43939.t (Wstat: 0 Tests: 4 Failed: 1) Failed test: 4 t/apache/pr49328.t (Wstat: 0 Tests: 1 Failed: 1) Failed test: 1 t/modules/deflate.t(Wstat: 0 Tests: 14 Failed: 10) Failed tests: 1-2, 4-11 Regards Rüdiger
Re: svn commit: r1482522 - in /httpd/httpd/trunk: ./ docs/log-message-tags/ include/ modules/dav/main/ modules/generators/ modules/http/ modules/proxy/ server/
On 15 May 2013, at 9:23 PM, Ruediger Pluem rpl...@apache.org wrote: Now we have: t/apache/pr17629.t (Wstat: 0 Tests: 4 Failed: 1) Failed test: 4 I get this: t/apache/pr17629.t .. 1..0 # skipped: cannot find module 'case_filter' skipped: cannot find module 'case_filter' Files=1, Tests=0, 1 wallclock secs ( 0.03 usr 0.01 sys + 0.63 cusr 0.33 csys = 1.00 CPU) Result: NOTESTS Let me figure out why the case_filter is missed and try this again. Regards, Graham --