httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Kris.Verbe...@ubizen.com
Subject mod_cache not serving cached pages
Date Mon, 29 Jul 2002 12:02:46 GMT

Hi,

I have a problem with letting Apache 2.0.39/mod_cache serve
cached pages.  When first requesting a page, the page is
being
cached (a disk file is present) but when performing a second
request, the cached page is not returned but a fresh page
is fetched.  Is this a configuration issue or problem with
mod_cache?

Relevant configuration section from httpd.conf:
  <VirtualHost [ip]:[port]>
    JkMount /* ajp13
    ServerName [hostname]
    
    
    <IfModule mod_ssl.c>
        SSLEngine off
        #  10   
        #  [certificate]
        #  [key]
        #  [caCertificate]
        #  +StdEnvVars +CompatEnvVars +ExportCertData
        
    </IfModule>
    <IfModule mod_mime.c>
        #  AddOutputFilter DEFLATE [deflateExtensions]
    </IfModule>
    <IfModule mod_cache.c>
        CacheOn            On
        CacheMaxExpire     604800
        CacheDefaultExpire 3600
        <IfModule mod_disk_cache.c> 
            CacheRoot    /cache 
            CacheEnable  disk /
             
        </IfModule> 
    </IfModule>
  </VirtualHost>


I have added some extra logging statements to the mod_cache
code to check which 'age' values are being used/calculated
for the cached page.  Logging has been set to debug and when 
performing a first request for a page, the following lines
are
logged:

[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(109): cache:
URL /omega/perl/pod/perlfunc/symlink.html is being handled
by disk
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(192): cache:
no cache - add cache_in filter and DECLINE
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(416): cache:
running CACHE_IN filter
[Mon Jul 29 13:34:43 2002] [info] disk_cache: Caching URL
/omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(643): cache:
Caching url: /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(684):
now       = 1027946083671195
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(685): set
rsp_t = 1027946083671195
[Mon Jul 29 13:34:43 2002] [info] disk_cache: Caching
headers for URL /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:43 2002] [debug] mod_cache.c(416): cache:
running CACHE_IN filter
[Mon Jul 29 13:34:43 2002] [info] disk_cache: Cached body
for URL /omega/perl/pod/perlfunc/symlink.html

The lines with 'now =' and 'set rsp_t =' were added by me. 
The
show the current time and response time (in usec since
1970).

Now, when performing a second request for the same page,
that
page should come rom the cache.  But:

[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(109): cache:
URL /omega/perl/pod/perlfunc/symlink.html is being handled
by disk
[Mon Jul 29 13:34:58 2002] [info] disk_cache: Serving Cached
URL /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:58 2002] [info] disk_cache: Served headers
for URL /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(253):
APR_DATE_BAD = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(254):
age          = 1027946098539476
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(255):
age_c        = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(256):
info->date   = 1027943206000000
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(257):
info->expire = 1028550883671195
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(258):
info->req_t  = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(259):
info->rsp_t  = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(260):
minfresh     = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(261):
maxage       = -1
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(262):
maxstale     = 0
[Mon Jul 29 13:34:58 2002] [debug] cache_util.c(263):
smaxage      = -1
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(247): cache:
stale cache - test conditional
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(283): cache:
nonconditional - no cached etag/lastmods - add cache_in and
DECLINE
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(416): cache:
running CACHE_IN filter
[Mon Jul 29 13:34:58 2002] [info] disk_cache: Caching URL
/omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(643): cache:
Caching url: /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(684):
now       = 1027946098584206
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(685): set
rsp_t = 1027946098584206
[Mon Jul 29 13:34:58 2002] [info] disk_cache: Caching
headers for URL /omega/perl/pod/perlfunc/symlink.html
[Mon Jul 29 13:34:58 2002] [debug] mod_cache.c(416): cache:
running CACHE_IN filter
[Mon Jul 29 13:34:58 2002] [info] disk_cache: Cached body
for URL /omega/perl/pod/perlfunc/symlink.html

>From line 4 to line 14 I printed some more debug values. 
These 
values are used to calculate the age of the request/response
and to check whether the cached version is still fresh.  The
problem here is that the info->request_time and 
info->response_time are zero, resulting in a very large age
value.  These values are zero because they are only filled
in
later on, i.e. a few lines lower you have the 'set rsp_t'
log
entry.

Does mod_cache behave like this because I misconfigured
something?  Or is it a problem in the code itself??

-- 
ir. Kris Verbeeck
Development Engineer

Ubizen - Ubicenter - Philipssite 5 - 3001 Leuven - Belgium
T:  +32 16 28 70 64
F:  +32 16 28 70 77

Ubizen - We Secure e-business - www.ubizen.com

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Mime
View raw message