You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@httpd.apache.org by Kr...@ubizen.com on 2002/08/14 10:55:24 UTC
mod_cache not serving cached files
Hi,
First of all, I also posted this mail on the Apache users
mailing
list but did not receive any solution for my problem.
That's why
I'm trying the dev mailing list now.
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.
They
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 from 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
RE: mod_cache not serving cached files
Posted by Bill Stoddard <bi...@wstoddard.com>.
mod_disk_cache is still broken. mod_mem_cache should work (w/o virtual
hosts) in 2.0.40. A couple of folks on the list have some fixes for
mod_disk_cache that will get into 2.0.41. Sorry for the inconvience.
Bill
> Hi,
>
> First of all, I also posted this mail on the Apache users
> mailing
> list but did not receive any solution for my problem.
> That's why
> I'm trying the dev mailing list now.
>
> 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.
> They
> 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 from 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
>