You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Dima Smirnov <go...@ogmc.ru> on 2002/09/02 12:35:32 UTC

[users@httpd] [?] Problem getting mod_cache to serve cached documents.

Greetings.

 Can anybody please advise me on the following problem: I'm having 
trouble getting mod_cache to work as expected on Apache 2.0.40 on
FreeBSD. Detailed description and problem research follows.

 1.  OS and software: Host name www.mysite2.ru running FreeBSD 4.3-RELEASE, 
Apache 2.0.40 compiled with mpm_prefork. Mod_proxy and mod_cache compiled as 
DSO's.

 2. Relevant configuration: 

--- Start part of httpd.conf ---

LogLevel debug

CacheRoot /var/apache2/proxy
CacheEnable disk /
CacheSize 256
CacheDirLevels 3
CacheDirLength 3
ProxyPass / http://www.mysite.ru/!!!/

--- End httpd.conf ---

The following file is named index.html and put into the location that
is recognized by Apache serving www.mysite.ru as the physical path for
www.mysite.ru/!!!/;

--- Start www.mysite.ru/!!!/index.html ---
<META NAME="Last-Modified" CONTENT="Mon, 02 Sep 2002 20:56:15 GMT">
<HTML>
Test!
</HTML>
---

 3. Procedures taken.

 $ wget http://www.mysite2.ru/index.html
 
 index.html appears. The following lines appear in www.mysite2.ru's error
log:

--- Start of error.log ---
[Mon Sep 02 21:00:32 2002] [debug] mod_cache.c(112): cache: URL /index.html is being handled by disk
[Mon Sep 02 21:00:32 2002] [debug] mod_cache.c(196): cache: no cache - add cache_in filter and DECLINE
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(109): proxy: HTTP: canonicalising URL //www.mysite.ru/!!!/index.html
[Mon Sep 02 21:00:32 2002] [debug] mod_proxy.c(461): Trying to run scheme_handler
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(1040): proxy: HTTP: serving URL http://www.mysite.ru/!!!/index.html
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(221): proxy: HTTP connecting http://www.mysite.ru/!!!/index.html to www.mysite.ru:80
[Mon Sep 02 21:00:32 2002] [debug] proxy_util.c(1167): proxy: HTTP: fam 2 socket created to connect to www.mysite.ru
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(370): proxy: socket is connected
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(404): proxy: connection complete to xxx.xx.xxx.xx:80 (www.mysite.ru)
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(882): proxy: start body send
[Mon Sep 02 21:00:32 2002] [debug] mod_cache.c(422): cache: running CACHE_IN filter
[Mon Sep 02 21:00:32 2002] [info] disk_cache: Caching URL /index.html
[Mon Sep 02 21:00:32 2002] [debug] mod_cache.c(651): cache: Caching url: /index.html
[Mon Sep 02 21:00:32 2002] [info] disk_cache: Caching headers for URL /index.html
[Mon Sep 02 21:00:32 2002] [debug] mod_cache.c(422): cache: running CACHE_IN filter
[Mon Sep 02 21:00:32 2002] [info] disk_cache: Cached body for URL /index.html
[Mon Sep 02 21:00:32 2002] [debug] proxy_http.c(941): proxy: end body send
--- End --- 

 Two files are also created in /var/apache2/proxy containing cached document
data.

 Now, one more request is performed, in hopes that www.mysite2.org's proxy
will perform a cache hit and won't access www.mysite.org again.

 $ wget http://www.mysite2.ru/index.html

 However, contrary to all expectations, a request if performed (and visible
in www.mysite.ru's access.log). The following lines are added to 
www.mysite2.ru's error log:

--- Start of error.log ---
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(112): cache: URL /index.html is being handled by disk
[Mon Sep 02 21:01:08 2002] [info] disk_cache: Serving Cached URL /index.html
[Mon Sep 02 21:01:08 2002] [info] disk_cache: Served headers for URL /index.html
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(252): cache: stale cache - test conditional
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(288): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(109): proxy: HTTP: canonicalising URL //www.mysite.ru/!!!/index.html
[Mon Sep 02 21:01:08 2002] [debug] mod_proxy.c(461): Trying to run scheme_handler
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(1040): proxy: HTTP: serving URL http://www.mysite.ru/!!!/index.html
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(221): proxy: HTTP connecting http://www.mysite.ru/!!!/index.html to www.mysite.ru:80
[Mon Sep 02 21:01:08 2002] [debug] proxy_util.c(1167): proxy: HTTP: fam 2 socket created to connect to www.mysite.ru
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(370): proxy: socket is connected
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(404): proxy: connection complete to xxx.xx.xxx.xx:80 (www.mysite.ru)
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(882): proxy: start body send
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(422): cache: running CACHE_IN filter
[Mon Sep 02 21:01:08 2002] [info] disk_cache: Caching URL /index.html
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(651): cache: Caching url: /index.html
[Mon Sep 02 21:01:08 2002] [info] disk_cache: Caching headers for URL /index.html
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(422): cache: running CACHE_IN filter
[Mon Sep 02 21:01:08 2002] [info] disk_cache: Cached body for URL /index.html
[Mon Sep 02 21:01:08 2002] [debug] proxy_http.c(941): proxy: end body send
--- End ---

 I THINK THIS IS AN ERROR AND I THINK THE DOCUMENT SHOULD'VE BEEN SERVED
FROM THE CACHE. I AM ASKING ANYBODY HAVING EXPERIENCE WITH MOD_CACHE TO
HELP ME OUT, PLEASE. You can find my research below.

 4. Research notes.

 First, I have performed the request for http://www.mysite2.ru/index.html 
using a telnet application. The output was:

--- Start telnet output ---
 GET /index.html HTTP/1.0

HTTP/1.1 200 OK
Date: Mon, 02 Sep 2002 21:08:38 GMT
Server: Apache/1.3.20 (Unix) mod_perl/1.26
Last-Modified: Mon, 02 Sep 2002 20:56:15 GMT
Content-Type: text/html; charset=ISO-8859-1
Age: 0
X-Cache: MISS from www.mysite2.ru
Content-Length: 84
Connection: close

<META NAME="Last-Modified" CONTENT="28-Aug-2002 23:53:00 GMT">
<HTML>
Test!
</HTML>

--- End ---

 So, mod_cache recieves a valid Last-Modified header but doesn't act on it.
Next, I've added the following option to the httpd.conf on www.mysite.ru;

--- Start of httpd.conf additions ---
XBitHack full
--- End ---

 Then, I set the group and user execute bit on the index.html file and performed
all the steps above again. The result is the same, except for the value of
the Last-Modified header. No cache hit is performed nonetheless.

 Having done that, I now go the source code for mod_disk_cache to see
where exactly does the error

--- Start of error.log ---
[Mon Sep 02 21:01:08 2002] [debug] mod_cache.c(288): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE
--- End ---

occur. The relevant code is found in the file 
modules/experimental/mod_cache.c in the apache distribution. The exact line
that raises this error is line 286:

--- Start of mod_cache.c:286 ---
/* something else - pretend there was no cache */
ap_log_error(APLOG_MARK, APLOG_DEBUG, 0,
r->server,
"cache: nonconditional - no cached "
"etag/lastmods - add cache_in and DECLINE");
--- End ---

This is caused by a condition check which is positioned on line 276.

--- Start of mod_cache.c:276 ---
 else if (info && info->lastmods) {
--- End ---

 So, we can see that a structure named info is checked for the presence
of HTTP response headers. Looking at the code we find that this 
structure is declared on line 94:

--- Start of mod_cache.c:94 ---
cache_info *info = NULL;
--- End ---

Besides this declaration, NO CHANGES ARE MADE TO THE CONTENTS OF info 
ELSEWHERE IN THE CODE BEFORE LINE 276. I lack the skills to do a proper
debug on the code in question, but looking at the code we can see that it
is not passed anywhere as a parameter and no modifications are ever done
to it. I THINK THIS IS WHAT CAUSES THE ERROR.

 Can anybody please look into the problem and possibly point out what
I'm missing? I'm really baffled and would appreciate any sort of help.

 Thank you for reading this to the end.

Best regards,
Dmitriy Smirnov.




---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org