Bug 13946 - reverse proxy errors when a document expires from the cache
Summary: reverse proxy errors when a document expires from the cache
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_cache (show other bugs)
Version: 2.0.44
Hardware: PC Linux
: P3 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords: PatchAvailable
Depends on:
Blocks:
 
Reported: 2002-10-24 19:45 UTC by Fabio Wakim Trentini
Modified: 2006-08-08 13:28 UTC (History)
0 users



Attachments
Patch to solve the probem (837 bytes, patch)
2003-01-31 19:36 UTC, Eider Oliveira
Details | Diff
Patch fix, now generated by a diff -u (2.09 KB, patch)
2003-01-31 20:06 UTC, Eider Oliveira
Details | Diff
Updated version of Fabio's patch from above. (current 2.1-dev branch) (1.96 KB, patch)
2003-07-10 19:12 UTC, Paul J. Reder
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Fabio Wakim Trentini 2002-10-24 19:45:36 UTC
Hi!
Using apache as a reverse proxy with mod_mem_cache, when using simple HTTP/1.0 
requests to files, sometimes (when the object in the cache is expired) the 
proxy does weird requisitions:

The request:
GET /index.html HTTP/1.0
Host: 10.0.0.2

Document cached:
[Fri Oct 25 18:52:07 2002] [debug] mod_cache.c(118): cache: URL /index.html is 
being handled by mem
[Fri Oct 25 18:52:07 2002] [debug] mod_cache.c(232): cache: fresh cache - add 
cache_out filter and handle request
[Fri Oct 25 18:52:07 2002] [debug] mod_cache.c(357): cache: running CACHE_OUT 
filter
[Fri Oct 25 18:52:07 2002] [debug] mod_cache.c(366): cache: serving cached 
version of /index.html

After the document expires:
[Fri Oct 25 18:59:00 2002] [debug] proxy_http.c(109): proxy: HTTP: 
canonicalising URL //10.0.0.2/proxy:http://10.0.0.2/index.html
[Fri Oct 25 18:59:00 2002] [debug] mod_proxy.c(461): Trying to run 
scheme_handler
[Fri Oct 25 18:59:00 2002] [debug] proxy_http.c(1061): proxy: HTTP: serving 
URL http://10.0.0.2/proxy:http://10.0.0.2/index.html
[Fri Oct 25 18:59:00 2002] [debug] proxy_http.c(221): proxy: HTTP connecting 
http://10.0.0.2/proxy:http://10.0.0.2/index.html to 10.0.0.2:80

and after a few mseconds:
[Fri Oct 25 18:59:00 2002] [debug] mod_cache.c(118): cache: URL /index.html is 
being handled by mem
[Fri Oct 25 18:59:00 2002] [debug] mod_cache.c(203): cache: no cache - add 
cache_in filter and DECLINE

Here is a piece of my httpd.conf file:
ProxyRequests Off
ProxyVia Full
ProxyTimeout 30
ProxyReceiveBufferSize 16384
ProxyMaxForwards 10
CacheEnable mem /
CacheDefaultExpire 10
CacheMaxExpire 30
CacheLastModifiedFactor 0.1
CacheMaxStreamingBuffer 65536 
MCacheSize 524288
MCacheMaxObjectCount 32768
MCacheMinObjectSize 1 
MCacheMaxObjectSize 100000
MCacheRemovalAlgorithm GDSF
RewriteEngine   on
RewriteRule     ^(.*)$     $1 [P,L]
Comment 1 Paul J. Reder 2002-12-05 02:07:08 UTC
Can you specify where you think the problem is in the log you attached?

If you are concerned about the "no cache - add cache_in filter and DECLINE" part
of the message, that is perfectly normal. This simply indicates that the cache
handler has noticed that new, cacheable content is arriving. It inserts the
cache_in filter into the filter chain so that the caching code can store the new
content as it flows through, but it returns "declined" to indicate that the
cache handler didn't process the response.

I'm going to wait a few days for a clarification on this. If there isn't
something I've missed here then I'll go ahead and close this PR at that point.
Comment 2 Paul J. Reder 2002-12-09 21:03:06 UTC
Having received no response to the contrary, I have to assume that this was not
actually a problem after all. I'm closing it now. It can be re-opened if someone
disagrees.
Comment 3 Fabio Wakim Trentini 2002-12-09 21:51:26 UTC
Hi, sorry for the delay.
Well, the error is right here:
---
[Fri Oct 25 18:59:00 2002] [debug] proxy_http.c(221): proxy: HTTP connecting 
http://10.0.0.2/proxy:http://10.0.0.2/index.html to 10.0.0.2:80
---

it tries to get the URL http://10.0.0.2/proxy:http://10.0.0.2/index.html, 
generating errors. it only happens when using mod_proxy with mod_rewrite. it 
looks like mod_rewrite appends the "http://10.0.0.2/proxy:" string, in the 
example, but *only* when the document expires from the cache.
Comment 4 Paul J. Reder 2002-12-09 22:13:53 UTC
Does the server return an error to the client or does the server succeed in
retrieving and returning the page from the proxy machine? In other words, is it
just a logging issue or does it actually fail to retrieve the page after it expires?

I don't see a log entry indicating that the page isn't found, and the only entry
in the log from the cache code indicates that it is inserting the
cache_in_filter to handle the page returned from the proxy.

Thanks for any additional info you can provide.
Comment 5 Fabio Wakim Trentini 2002-12-09 22:22:31 UTC
in all these requests, the server returns an error to the client.
Comment 6 Paul J. Reder 2002-12-09 23:20:19 UTC
What is the error returned to the client and what error(s) get logged into the
server's error_log or access_log?
Comment 7 Graham Leggett 2003-01-22 10:43:07 UTC
This seems to be a mod_cache bug
Comment 8 Fabio Wakim Trentini 2003-01-28 18:05:18 UTC
hi there,
the bug persists in httpd-2.0.44. Here is some piece of the error_log:

[Tue Jan 28 15:48:23 2003] [error] [client 200.164.36.73] proxy: URI cannot be 
parsed: http://xxx.com.brproxy:http//xxx.com.br/imagens/pix.gif returned 
by /imagens/pix.gif
[Tue Jan 28 15:48:23 2003] [error] [client 200.207.161.223] proxy: URI cannot 
be parsed: http://xxx.com.brproxy:http//xxx.com.br/beach/t3.jpg returned 
by /beach/t3.jpg, referer: http://xxx.com.br/beach/left.html
[Tue Jan 28 15:48:23 2003] [error] [client 200.191.233.186] proxy: URI cannot 
be parsed: http://yyy.com.brproxy:http//yyy.com.br/imagens/b.gif returned 
by /imagens/b.gif, referer: http://yyy.com.br/
Comment 9 Fabio Wakim Trentini 2003-01-28 18:10:28 UTC
another error:

access_log:
200.174.198.133 - - [28/Jan/2003:15:47:18 - 0200] "GET /js/video.js HTTP/1.1" 
400 498 "http://xxx.com.br/" "Mozilla/4.0 (compatible; MSIE 6.0; Windows 98)"

error_log:
[Tue Jan 28 15:47:18 2003] [error] [client 200.174.198.133] proxy: URI cannot 
be parsed: http://xxx.com.brproxy:http//xxx.com.br/js/video.js returned 
by /js/video.js, referer: http://xxx.com.br/

It *only* happens with mod_rewrite with reverse proxy.
Comment 10 Eider Oliveira 2003-01-31 19:36:18 UTC
Created attachment 4670 [details]
Patch to solve the probem
Comment 11 Eider Oliveira 2003-01-31 19:41:06 UTC
A did attach a patch to solve this bug. It is caused when the mod_rewrite 
reprocess the request after mod_proxy return it.
Comment 12 Eider Oliveira 2003-01-31 20:06:17 UTC
Created attachment 4671 [details]
Patch fix, now generated by a diff -u
Comment 13 Cliff Woolley 2003-01-31 21:07:05 UTC
Let's not mark this as resolved/fixed until a fix is actually committed... 
otherwise the patch might get lost.  :)

Thanks,
Cliff
Comment 14 André Malo 2003-06-01 17:48:55 UTC
Is this fixed now or not? :-)
Comment 15 Paul J. Reder 2003-07-09 18:03:03 UTC
I'm currently looking into porting the old patch to the current code, verifying
the patch, and committing it to cvs. I am not convinced that this part of the
patch needs to be present since we aren't seeing "proxy:proxy:" which is what
this if statement would prevent...

@@ -2082,6 +2098,7 @@
             rewritelog(r, 2, "[per-dir %s] forcing proxy-throughput with %s",
                        perdir, r->filename);
         }
+        if (strncasecmp("proxy:",r->filename,6))
         r->filename = apr_pstrcat(r->pool, "proxy:", r->filename, NULL);
         return 1;
     }
Comment 16 Paul J. Reder 2003-07-10 19:12:49 UTC
Created attachment 7229 [details]
Updated version of Fabio's patch from above. (current 2.1-dev branch)
Comment 17 Paul J. Reder 2003-07-14 16:51:54 UTC
I have tested the updated patch and committed it to the Apache 2.1-dev branch. I
will submit it for a vote to backport to the 2.0-stable branch. Thank you for
your efforts in identifying and fixing this bug.
Comment 18 André Malo 2003-08-18 00:03:01 UTC
Perhaps I'm missing something... The provided config:

ProxyRequests Off
ProxyVia Full
ProxyTimeout 30
ProxyReceiveBufferSize 16384
ProxyMaxForwards 10
CacheEnable mem /
CacheDefaultExpire 10
CacheMaxExpire 30
CacheLastModifiedFactor 0.1
CacheMaxStreamingBuffer 65536 
MCacheSize 524288
MCacheMaxObjectCount 32768
MCacheMinObjectSize 1 
MCacheMaxObjectSize 100000
MCacheRemovalAlgorithm GDSF
RewriteEngine   on
RewriteRule     ^(.*)$     $1 [P,L]

creates an infinite loop (proxying to itself), doesn't it? Why is this useful?
Comment 19 Jeff Trawick 2003-11-21 22:13:35 UTC
updating PRs to add PatchAvailable keyword
For updated information on submitting patches, see
http://httpd.apache.org/dev/patches.html
Comment 20 Paul Querna 2005-06-03 02:36:25 UTC
Can you test this on 2.0.54? Lots of things in both proxy and cache have been
changed since this was last reported.
Comment 21 Nick Kew 2006-08-08 20:28:37 UTC
No activity after a very long time in NEEDINFO; assuming expired.