Hi, I submitted this behaviour on modproxy-dev mailing list but no one replied ...
i added mod_cache on my reverse proxy, and i noticed a strange behaviour. Here is how i use mod_cache: <VirtualHost 192.168.100.19:80> ServerName web1.test.com ProxyPass / http://web1.test.com/ ProxyPassReverse / http://web1.test.com/ TransferLog /dev/null ErrorLog /logs/1-error.log CacheOn On CacheEnable mem / MCacheSize 64000 MCacheMaxObjectSize 100000 #CacheIgnoreCacheControl on #CacheExpiryCheck off </VirtualHost> Now i tell a Lynx client to get http://web1.test.com/index.html.fr (default apache page). Here are the logs on the reverse proxy: ==> /logs/1-error.log <== [Thu Jun 13 13:06:35 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by mem [Thu Jun 13 13:06:35 2002] [debug] mod_cache.c(194): cache: no cache - add cache_in filter and DECLINE [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(445): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 13:06:35 2002] [debug] mod_proxy.c(464): Trying to run scheme_handler [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(1462): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(571): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 13:06:35 2002] [debug] proxy_util.c(1210): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(741): proxy: socket is connected [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(780): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(1287): proxy: start body send [Thu Jun 13 13:06:35 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:06:35 2002] [debug] proxy_http.c(1352): proxy: end body send Now i quit lynx, then i relaunch it and i make the same request. Here is the reverse proxy log for the new request: [Thu Jun 13 13:08:04 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by mem [Thu Jun 13 13:08:04 2002] [debug] mod_cache.c(194): cache: no cache - add cache_in filter and DECLINE [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(445): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 13:08:04 2002] [debug] mod_proxy.c(464): Trying to run scheme_handler [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(1462): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(571): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 13:08:04 2002] [debug] proxy_util.c(1210): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(741): proxy: socket is connected [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(780): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(1287): proxy: start body send [Thu Jun 13 13:08:04 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:08:04 2002] [debug] proxy_http.c(1352): proxy: end body send As you can see, it's exactly the same as if the request had never been made before ... mod_cache says the page is not known and not cached. But if i use mod_disk instead of mod_mem, i can see the page requested inside the CacheRoot directory. Same problem with mod_disk: [root]# du -abc /cache/ 4096 /cache/web1 8192 /cache 8192 total I launch the first lynx request, here are the logs on the reverse proxy: ==> /logs/1-error.log <== [Thu Jun 13 13:22:43 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by disk [Thu Jun 13 13:22:43 2002] [debug] mod_cache.c(194): cache: no cache - add cache_in filter and DECLINE [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(445): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 13:22:43 2002] [debug] mod_proxy.c(464): Trying to run scheme_handler [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(1462): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(571): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 13:22:43 2002] [debug] proxy_util.c(1210): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(741): proxy: socket is connected [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(780): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(1287): proxy: start body send [Thu Jun 13 13:22:43 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:22:43 2002] [info] disk_cache: Caching URL /index.html.fr [Thu Jun 13 13:22:43 2002] [debug] mod_cache.c(650): cache: Caching url: /index.html.fr [Thu Jun 13 13:22:43 2002] [info] disk_cache: Caching headers for URL /index.html.fr [Thu Jun 13 13:22:43 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:22:43 2002] [info] disk_cache: Cached body for URL /index.html.fr [Thu Jun 13 13:22:43 2002] [debug] proxy_http.c(1352): proxy: end body send I close Lynx. [root]# du -abc /cache/ 4096 /cache/web1/ib/LS/NJ/Qa@[EMAIL PROTECTED] 4096 /cache/web1/ib/LS/NJ/Qa@[EMAIL PROTECTED] 12288 /cache/web1/ib/LS/NJ 16384 /cache/web1/ib/LS 20480 /cache/web1/ib 24576 /cache/web1 28672 /cache 28672 total I start a second request, here are the logs: [Thu Jun 13 13:23:52 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by disk [Thu Jun 13 13:23:52 2002] [debug] mod_cache.c(194): cache: no cache - add cache_in filter and DECLINE [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(445): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 13:23:52 2002] [debug] mod_proxy.c(464): Trying to run scheme_handler [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(1462): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(571): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 13:23:52 2002] [debug] proxy_util.c(1210): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(741): proxy: socket is connected [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(780): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 13:23:52 2002] [debug] proxy_http.c(1287): proxy: start body send [Thu Jun 13 13:23:52 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:23:52 2002] [info] disk_cache: Caching URL /index.html.fr [Thu Jun 13 13:23:52 2002] [debug] mod_cache.c(650): cache: Caching url: /index.html.fr [Thu Jun 13 13:23:53 2002] [info] disk_cache: Caching headers for URL /index.html.fr [Thu Jun 13 13:23:53 2002] [debug] mod_cache.c(419): cache: running CACHE_IN filter [Thu Jun 13 13:23:53 2002] [info] disk_cache: Cached body for URL /index.html.fr [Thu Jun 13 13:23:53 2002] [debug] proxy_http.c(1352): proxy: end body send It still says the cache does not known this URL. Server logs always display the same line: 192.168.100.19 - - [13/Jun/2002:13:23:35 +0200] "GET /index.html.fr HTTP/1.1" 200 1505 I then found a little patch to adress te mod_disk problem by changing line 548 in mod_disk_cache.c, and it worked: the second request was fully handled by cache, and no request was sent to the server. But i still can't use the mod_mem_cache module ... I tried the CVS version of apache, and it broke again mod_disk_cache : 1st request log: [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by disk [Thu Jun 13 15:50:06 2002] [info] disk_cache: Serving Cached URL /index.html.fr [Thu Jun 13 15:50:06 2002] [info] disk_cache: Served headers for URL /index.html.fr [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(247): cache: stale cache - test conditional [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(283): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(109): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 15:50:06 2002] [debug] mod_proxy.c(461): Trying to run scheme_handler [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(1040): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(221): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 15:50:06 2002] [debug] proxy_util.c(1167): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(370): proxy: socket is connected [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(404): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(882): proxy: start body send [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(416): cache: running CACHE_IN filter [Thu Jun 13 15:50:06 2002] [info] disk_cache: Caching URL /index.html.fr [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(647): cache: Caching url: /index.html.fr [Thu Jun 13 15:50:06 2002] [info] disk_cache: Caching headers for URL /index.html.fr [Thu Jun 13 15:50:06 2002] [debug] mod_cache.c(416): cache: running CACHE_IN filter [Thu Jun 13 15:50:06 2002] [info] disk_cache: Cached body for URL /index.html.fr [Thu Jun 13 15:50:06 2002] [debug] proxy_http.c(941): proxy: end body send 2nd request log: [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by disk [Thu Jun 13 15:50:28 2002] [info] disk_cache: Serving Cached URL /index.html.fr [Thu Jun 13 15:50:28 2002] [info] disk_cache: Served headers for URL /index.html.fr [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(247): cache: stale cache - test conditional [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(283): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(109): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 15:50:28 2002] [debug] mod_proxy.c(461): Trying to run scheme_handler [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(1040): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(221): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 15:50:28 2002] [debug] proxy_util.c(1167): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(370): proxy: socket is connected [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(404): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(882): proxy: start body send [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(416): cache: running CACHE_IN filter [Thu Jun 13 15:50:28 2002] [info] disk_cache: Caching URL /index.html.fr [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(647): cache: Caching url: /index.html.fr [Thu Jun 13 15:50:28 2002] [info] disk_cache: Caching headers for URL /index.html.fr [Thu Jun 13 15:50:28 2002] [debug] mod_cache.c(416): cache: running CACHE_IN filter [Thu Jun 13 15:50:28 2002] [info] disk_cache: Cached body for URL /index.html.fr [Thu Jun 13 15:50:28 2002] [debug] proxy_http.c(941): proxy: end body send Now if i enable mem cache instead of disk cache: [Thu Jun 13 16:10:31 2002] [debug] mod_cache.c(109): cache: URL /index.html.fr is being handled by mem [Thu Jun 13 16:10:31 2002] [debug] mod_cache.c(192): cache: no cache - add cache_in filter and DECLINE [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(109): proxy: HTTP: canonicalising URL //web1.test.com/index.html.fr [Thu Jun 13 16:10:31 2002] [debug] mod_proxy.c(461): Trying to run scheme_handler [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(1040): proxy: HTTP: serving URL http://web1.test.com/index.html.fr [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(221): proxy: HTTP connecting http://web1.test.com/index.html.fr to web1.test.com:80 [Thu Jun 13 16:10:31 2002] [debug] proxy_util.c(1167): proxy: HTTP: fam 2 socket created to connect to web1.test.com [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(370): proxy: socket is connected [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(404): proxy: connection complete to 192.168.100.5:80 (web1.test.com) [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(882): proxy: start body send [Thu Jun 13 16:10:31 2002] [debug] mod_cache.c(416): cache: running CACHE_IN filter [Thu Jun 13 16:10:31 2002] [debug] mod_mem_cache.c(438): cache_mem: URL /index.html.fr failed the size check, or is incomplete [Thu Jun 13 16:10:31 2002] [debug] proxy_http.c(941): proxy: end body send i'm lost :( thanks for your help, Arnauld Dravet [EMAIL PROTECTED]
