DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT <http://issues.apache.org/bugzilla/show_bug.cgi?id=30370>. ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=30370 Pages cached in more than one cache remain stale although it is revalidated. Summary: Pages cached in more than one cache remain stale although it is revalidated. Product: Apache httpd-2.0 Version: 2.0.49 Platform: All OS/Version: Other Status: NEW Severity: Normal Priority: Other Component: mod_cache AssignedTo: [email protected] ReportedBy: [EMAIL PROTECTED] On a reverse proxy, centuri, we have both disk cache and mem cache activated. The memory cache is activated first and is only supposed to cache elements of size smaller than 10,000 bytes. The disk cache takes care of anything not cached by the memory cache. Somehow, at one point a file of size smaller than 10,000 bytes ends up being cached by the disk cache. Don't ask me why (maybe the mem cache was filled up and the element ended up on disk?) - it's beyond the point. Eventually, the file in disk cache ends up stale. At that point, when the element (style.css) is requested, the disk cache responds that it is stale and a proxy request is issued to the backend server. The fresh element ends up being cached in memory since it is smaller than 10 KB, and the stale entry remains in the disk cache... When the caches are queried, it seems like the disk cache is always queried first. The logs below should clearly show what happens. mod_disk_cache does not appear to log the element as stale, but I know that the disk cache contains a stale copy of styles.css because I looked it up in the file system. Removing the element from the disk cache also removes the symptoms. Please find below the log trace of two requests for the same element style.css on the reverse proxy centuri:3080. The backend server is backend:7010. The two requests are separated by some CRs. [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(66): proxy: HTTP: canonicalising URL //centuri:3080/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] mod_proxy.c(416): Trying to run scheme_handler [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(1042): proxy: HTTP: serving URL http://centuri:3080/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(178): proxy: HTTP connecting http://centuri:3080/html/styles.css to centuri:3080 [Mon Jun 07 08:48:57 2004] [debug] proxy_util.c(1160): proxy: HTTP: fam 2 socket created to connect to centuri [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(327): proxy: socket is connected [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(361): proxy: connection complete to 150.175.10.189:3080 (centuri) [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(344): cache: stale cache - test conditional [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(391): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(66): proxy: HTTP: canonicalising URL //backend:7010/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] mod_proxy.c(416): Trying to run scheme_handler [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(1042): proxy: HTTP: serving URL http://backend:7010/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(178): proxy: HTTP connecting http://backend:7010/html/styles.css to backend:7010 [Mon Jun 07 08:48:57 2004] [debug] proxy_util.c(1160): proxy: HTTP: fam 2 socket created to connect to backend [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(327): proxy: socket is connected [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(361): proxy: connection complete to backend:7010 (backend) [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(877): proxy: start body send [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(532): cache: running CACHE_IN filter [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(790): cache: Caching url: /html/styles.css [Mon Jun 07 08:48:57 2004] [info] mem_cache: Cached url: centuri/html/styles.css? [Mon Jun 07 08:48:57 2004] [debug] mod_headers.c(521): headers: ap_headers_output_filter() [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(936): proxy: end body send [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(877): proxy: start body send [Mon Jun 07 08:48:57 2004] [debug] mod_headers.c(521): headers: ap_headers_output_filter() [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(936): proxy: end body send [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(66): proxy: HTTP: canonicalising URL //centuri:3080/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] mod_proxy.c(416): Trying to run scheme_handler [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(1042): proxy: HTTP: serving URL http://centuri:3080/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(178): proxy: HTTP connecting http://centuri:3080/html/styles.css to centuri:3080 [Mon Jun 07 08:48:57 2004] [debug] proxy_util.c(1160): proxy: HTTP: fam 2 socket created to connect to centuri [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(327): proxy: socket is connected [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(361): proxy: connection complete to 150.175.10.189:3080 (centuri) [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(344): cache: stale cache - test conditional [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(391): cache: nonconditional - no cached etag/lastmods - add cache_in and DECLINE [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(66): proxy: HTTP: canonicalising URL //backend:7010/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] mod_proxy.c(416): Trying to run scheme_handler [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(1042): proxy: HTTP: serving URL http://backend:7010/html/styles.css [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(178): proxy: HTTP connecting http://backend:7010/html/styles.css to backend:7010 [Mon Jun 07 08:48:57 2004] [debug] proxy_util.c(1160): proxy: HTTP: fam 2 socket created to connect to backend [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(327): proxy: socket is connected [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(361): proxy: connection complete to backend:7010 (backend) [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(877): proxy: start body send [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(532): cache: running CACHE_IN filter [Mon Jun 07 08:48:57 2004] [debug] mod_cache.c(790): cache: Caching url: /html/styles.css [Mon Jun 07 08:48:57 2004] [info] mem_cache: Cached url: centuri/html/styles.css? [Mon Jun 07 08:48:57 2004] [debug] mod_headers.c(521): headers: ap_headers_output_filter() [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(936): proxy: end body send [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(877): proxy: start body send [Mon Jun 07 08:48:57 2004] [debug] mod_headers.c(521): headers: ap_headers_output_filter() [Mon Jun 07 08:48:57 2004] [debug] proxy_http.c(936): proxy: end body send And the cache configuration: MCacheMaxObjectSize 10000 MCacheSize 70000 CacheEnable mem / CacheRoot /apache/cache CacheSize 150000 CacheEnable disk / So, during the first request for style.css, the disk cache is stale. A new copy of the file is retrieved from the backend and stored in memory cache. Then we issue a second request, and it turns out the cached copy is still stale... This behaviour was observed on Sun Solaris 8, but from what I saw in the code, there is no reason to think it would behave differently on other platforms. --------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
