Mailing List Archive

often mod_proxy cache revalidates
Hi,

from 2.4.48 on, mod_proxy-cache example [1] begins to fail for me.
Unfortunately I can not manage to expose this issue outside
apache-rex framework sofar. With 2.4.46, I can not see this at all.

$ git clone https://github.com/pgajdos/apache-rex.git
$ cd apache-rex
$ ./run-rex mod_proxy-cache
[..]
[1] reverse proxy with cache
< X-Cache: MISS from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
1 misses, 0 revalidates and 9 hits
[2] forward proxy with cache
< X-Cache: MISS from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
1 misses, 9 revalidates and 0 hits

Example FAILED (subexample #2):
[..]
$

Former behavior for 2.4.46:

[1] reverse proxy with cache
< X-Cache: MISS from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
1 misses, 0 revalidates and 9 hits
[2] forward proxy with cache
< X-Cache: MISS from test
< X-Cache: REVALIDATE from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
1 misses, 1 revalidates and 8 hits

Roughly: the example config (/tmp/apache-rex/mod_proxy-cache/httpd.conf) looks like:

------------------------------8<------------------------------------
ServerName test
User abuild
Group abuild
Listen 60080
PidFile /tmp/apache-rex/mod_proxy-cache/pid
ErrorLog /tmp/apache-rex/mod_proxy-cache/error_log
LoadModule auth_basic_module /usr/lib64/apache2-prefork/mod_auth_basic.so
LoadModule dir_module /usr/lib64/apache2-prefork/mod_dir.so
LoadModule authz_host_module /usr/lib64/apache2-prefork/mod_authz_host.so
LoadModule proxy_module /usr/lib64/apache2-prefork/mod_proxy.so
LoadModule proxy_http_module /usr/lib64/apache2-prefork/mod_proxy_http.so
LoadModule cache_module /usr/lib64/apache2-prefork/mod_cache.so
LoadModule log_config_module /usr/lib64/apache2-prefork/mod_log_config.so
LoadModule authz_core_module /usr/lib64/apache2-prefork/mod_authz_core.so
LoadModule cache_socache_module /usr/lib64/apache2-prefork/mod_cache_socache.so
LoadModule socache_shmcb_module /usr/lib64/apache2-prefork/mod_socache_shmcb.so
DocumentRoot /tmp/apache-rex/mod_proxy-cache/htdocs
DirectoryIndex index.html

### example configuration

LogFormat "%s %{cache-status}e" cache_format

Listen 60081
<VirtualHost *:60081>
ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-backend"
DocumentRoot "/tmp/apache-rex/mod_proxy-cache/htdocs-backend"
<Directory "/tmp/apache-rex/mod_proxy-cache/htdocs-backend">
Require local
</Directory>
</VirtualHost>

Listen 60082
<VirtualHost *:60082>
ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-reverse-proxy"

<Location "/app/">
ProxyPass "http://localhost:60081/"
</Location>

CacheSocache shmcb
CacheSocacheMaxSize 102400
CacheEnable socache "/"

CacheHeader on

CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-uncached.log" cache_format env=cache-miss
CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-cached.log" cache_format env=cache-hit
CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-revalidated.log" cache_format env=cache-revalidate
</VirtualHost>

Listen 60083
<VirtualHost *:60083>
ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-forward-proxy"

ProxyRequests On
<Proxy "*">
Require local
</Proxy>

CacheSocache shmcb
CacheSocacheMaxSize 102400
# http://httpd.apache.org/docs/current/mod/mod_cache.html#cacheenable
CacheEnable socache http://localhost:60081/

CacheHeader on

CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-uncached.log" cache_format env=cache-miss
CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-cached.log" cache_format env=cache-hit
CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-revalidated.log" cache_format env=cache-revalidate
</VirtualHost>
------------------------------>8------------------------------------

And the script runs 10 requests on the server:

for i in $(seq 1 10); do
curl -s -v --proxy http://localhost:60083/ http://localhost:60081/ 2>&1 | grep 'X-Cache'
sleep 0.1
done


And again, I cannot reproduce for example with httpd run with
fx. -f /tmp/apache-rex/mod_proxy-cache/httpd.conf and running requests
manually. I will try harder, I just want to know first whether this is
something known or whether I have something completely wrong in the
configuration.

Thanks for your attention,
Petr

[1] https://github.com/pgajdos/apache-rex/tree/master/mod_proxy-cache

--
Have a lot of fun!
Re: often mod_proxy cache revalidates [ In reply to ]
Hi,

how to more easily reproduce: with following configuration file,
located e. g. in /tmp/apache-rex/mod_proxy-cache/httpd.conf:


On Wed, Jun 16, 2021 at 01:01:59PM +0200, pgajdos wrote:
> ------------------------------8<------------------------------------
> ServerName test
> User abuild
> Group abuild
> Listen 60080
> PidFile /tmp/apache-rex/mod_proxy-cache/pid
> ErrorLog /tmp/apache-rex/mod_proxy-cache/error_log
> LoadModule auth_basic_module /usr/lib64/apache2-prefork/mod_auth_basic.so
> LoadModule dir_module /usr/lib64/apache2-prefork/mod_dir.so
> LoadModule authz_host_module /usr/lib64/apache2-prefork/mod_authz_host.so
> LoadModule proxy_module /usr/lib64/apache2-prefork/mod_proxy.so
> LoadModule proxy_http_module /usr/lib64/apache2-prefork/mod_proxy_http.so
> LoadModule cache_module /usr/lib64/apache2-prefork/mod_cache.so
> LoadModule log_config_module /usr/lib64/apache2-prefork/mod_log_config.so
> LoadModule authz_core_module /usr/lib64/apache2-prefork/mod_authz_core.so
> LoadModule cache_socache_module /usr/lib64/apache2-prefork/mod_cache_socache.so
> LoadModule socache_shmcb_module /usr/lib64/apache2-prefork/mod_socache_shmcb.so
> DocumentRoot /tmp/apache-rex/mod_proxy-cache/htdocs
> DirectoryIndex index.html
>
> ### example configuration
>
> LogFormat "%s %{cache-status}e" cache_format
>
> Listen 60081
> <VirtualHost *:60081>
> ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-backend"
> DocumentRoot "/tmp/apache-rex/mod_proxy-cache/htdocs-backend"
> <Directory "/tmp/apache-rex/mod_proxy-cache/htdocs-backend">
> Require local
> </Directory>
> </VirtualHost>
>
> Listen 60082
> <VirtualHost *:60082>
> ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-reverse-proxy"
>
> <Location "/app/">
> ProxyPass "http://localhost:60081/"
> </Location>
>
> CacheSocache shmcb
> CacheSocacheMaxSize 102400
> CacheEnable socache "/"
>
> CacheHeader on
>
> CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-uncached.log" cache_format env=cache-miss
> CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-cached.log" cache_format env=cache-hit
> CustomLog "/tmp/apache-rex/mod_proxy-cache/reverse-proxy-revalidated.log" cache_format env=cache-revalidate
> </VirtualHost>
>
> Listen 60083
> <VirtualHost *:60083>
> ErrorLog "/tmp/apache-rex/mod_proxy-cache/error_log-forward-proxy"
>
> ProxyRequests On
> <Proxy "*">
> Require local
> </Proxy>
>
> CacheSocache shmcb
> CacheSocacheMaxSize 102400
> # http://httpd.apache.org/docs/current/mod/mod_cache.html#cacheenable
> CacheEnable socache http://localhost:60081/
>
> CacheHeader on
>
> CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-uncached.log" cache_format env=cache-miss
> CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-cached.log" cache_format env=cache-hit
> CustomLog "/tmp/apache-rex/mod_proxy-cache/forward-proxy-revalidated.log" cache_format env=cache-revalidate
> </VirtualHost>
> ------------------------------>8------------------------------------

following script:

--------------------------------8<------------------------------------
mkdir -p /tmp/apache-rex/mod_proxy-cache/htdocs-backend
echo 'Backend for reverse' > /tmp/apache-rex/mod_proxy-cache/htdocs-backend/index.html

sleep 1

echo "[2] forward proxy with cache"
for i in $(seq 1 10); do
curl -s -v --proxy http://localhost:60083/ http://localhost:60081/ 2>&1 | grep 'X-Cache'
sleep 0.1
done
-------------------------------->8------------------------------------

gives:

$ sh run.sh
[2] forward proxy with cache
< X-Cache: MISS from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
< X-Cache: REVALIDATE from test
$

Altering (or touching) the the index file is essential, as well as the
sleep afterwards.

Petr

--
Have a lot of fun!
Re: often mod_proxy cache revalidates [ In reply to ]
On Mon, Jun 21, 2021 at 03:06:38PM +0200, pgajdos wrote:
> --------------------------------8<------------------------------------
> mkdir -p /tmp/apache-rex/mod_proxy-cache/htdocs-backend
> echo 'Backend for reverse' > /tmp/apache-rex/mod_proxy-cache/htdocs-backend/index.html
>
> sleep 1
>
> echo "[2] forward proxy with cache"
> for i in $(seq 1 10); do
> curl -s -v --proxy http://localhost:60083/ http://localhost:60081/ 2>&1 | grep 'X-Cache'
> sleep 0.1
> done
> -------------------------------->8------------------------------------
>
> gives:
>
> $ sh run.sh
> [2] forward proxy with cache
> < X-Cache: MISS from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> < X-Cache: REVALIDATE from test
> $
>
> Altering (or touching) the the index file is essential, as well as the
> sleep afterwards.

In other words, when I remove the sleep, I get, without restaring
httpd:

[2] forward proxy with cache
< X-Cache: MISS from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test
< X-Cache: HIT from test

Furthermore:
When I add the sleep now and do not restart httpd, I get the same
output, 9xHIT. I need to restart httpd first to get 9xREVALIDATE
again.

Petr

--
Have a lot of fun!