diff --git a/CHANGES b/CHANGES index a892b05d4d..e19ba00d5d 100644 --- a/CHANGES +++ b/CHANGES @@ -2,6 +2,11 @@ Changes with Apache 2.3.9 + *) mod_cache: Add the cache_status hook to register the final cache + decision hit/miss/revalidate. Add optional support for an X-Cache + and/or an X-Cache-Detail header to add the cache status to the + response. PR48241 [Graham Leggett] + *) mod_authz_host: Add 'local' provider that matches connections originating on the local host. PR 19938. [Stefan Fritsch] diff --git a/docs/manual/env.xml b/docs/manual/env.xml index e92f0002bf..055f69e7d9 100644 --- a/docs/manual/env.xml +++ b/docs/manual/env.xml @@ -59,6 +59,7 @@ Setting Environment Variables + mod_cache mod_env mod_rewrite mod_setenvif diff --git a/docs/manual/mod/mod_cache.xml b/docs/manual/mod/mod_cache.xml index 52ef81204a..9d5ac8ce1f 100644 --- a/docs/manual/mod/mod_cache.xml +++ b/docs/manual/mod/mod_cache.xml @@ -226,6 +226,39 @@ +
Cache Status and Logging +

Once mod_cache has made a decision as to whether or not + an entity is to be served from cache, the detailed reason for the decision + is written to the subprocess environment within the request under the + cache-status key. This reason can be logged by the + LogFormat directive as + follows:

+ + + LogFormat "%{cache-status}e ..." + + +

Based on the caching decision made, the reason is also written to the + subprocess environment under one the following three keys, as appropriate:

+ +
+
cache-hit
The response was served from cache.
+
cache-revalidate
The response was stale and was successfully + revalidated, then served from cache.
+
cache-miss
The response was served from the upstream server.
+
+ +

This makes it possible to support conditional logging of cached requests + as per the following example:

+ + + CustomLog cached-requests.log common env=cache-hit
+ CustomLog uncached-requests.log common env=cache-miss
+ CustomLog revalidated-requests.log common env=cache-revalidate
+ + +
+ CacheEnable Enable caching of specified URLs using a specified storage @@ -777,5 +810,87 @@ LastModified date. + + +CacheHeader +Add an X-Cache header to the response. +CacheHeader on|off +CacheHeader off +server config + virtual host + directory + .htaccess + +Available in Apache 2.3.9 and later + +

When the CacheHeader directive + is switched on, an X-Cache header will be added to the response + with the cache status of this response. If the normal handler is used, this + directive may appear within a <Directory> + or <Location> directive. If the quick + handler is used, this directive must appear within a server or virtual host + context, otherwise the setting will be ignored.

+ +
+
HIT
The entity was fresh, and was served from + cache.
+
REVALIDATE
The entity was stale, was successfully + revalidated and was served from cache.
+
MISS
The entity was fetched from the upstream + server and was not served from cache.
+
+ + + # Enable the X-Cache header
+ CacheHeader on
+ + + + X-Cache: HIT from localhost
+ + + + + + +CacheDetailHeader +Add an X-Cache-Detail header to the response. +CacheDetailHeader on|off +CacheDetailHeader off +server config + virtual host + directory + .htaccess + +Available in Apache 2.3.9 and later + + +

When the CacheDetailHeader directive + is switched on, an X-Cache-Detail header will be added to the response + containing the detailed reason for a particular caching decision.

+ +

It can be useful during development of cached RESTful services to have additional + information about the caching decision written to the response headers, so as to + confirm whether Cache-Control and other headers have been correctly + used by the service and client.

+ +

If the normal handler is used, this directive may appear within a + <Directory> or + <Location> directive. If the quick handler + is used, this directive must appear within a server or virtual host context, otherwise + the setting will be ignored.

+ + + # Enable the X-Cache-Detail header
+ CacheDetailHeader on
+ + + + X-Cache-Detail: "conditional cache hit: entity refreshed" from localhost
+ + + + + diff --git a/include/ap_mmn.h b/include/ap_mmn.h index ce0b957482..b147c5e108 100644 --- a/include/ap_mmn.h +++ b/include/ap_mmn.h @@ -269,6 +269,7 @@ * ap_cache_try_lock, ap_cache_check_freshness, * cache_server_conf, cache_enable, cache_disable, * cache_request_rec and cache_provider_list private. + * 20100923.1 (2.3.9-dev) Add cache_status hook. */ #define MODULE_MAGIC_COOKIE 0x41503234UL /* "AP24" */ @@ -276,7 +277,7 @@ #ifndef MODULE_MAGIC_NUMBER_MAJOR #define MODULE_MAGIC_NUMBER_MAJOR 20100923 #endif -#define MODULE_MAGIC_NUMBER_MINOR 0 /* 0...n */ +#define MODULE_MAGIC_NUMBER_MINOR 1 /* 0...n */ /** * Determine if the server's current MODULE_MAGIC_NUMBER is at least a diff --git a/modules/cache/cache_util.h b/modules/cache/cache_util.h index 42af41ca4f..fc1cf3ed7d 100644 --- a/modules/cache/cache_util.h +++ b/modules/cache/cache_util.h @@ -92,11 +92,12 @@ extern "C" { #define DEFAULT_CACHE_EXPIRE MSEC_ONE_HR #define DEFAULT_CACHE_LMFACTOR (0.1) #define DEFAULT_CACHE_MAXAGE 5 +#define DEFAULT_X_CACHE 0 +#define DEFAULT_X_CACHE_DETAIL 0 #define DEFAULT_CACHE_LOCKPATH "/mod_cache-lock" #define CACHE_LOCKNAME_KEY "mod_cache-lockname" #define CACHE_LOCKFILE_KEY "mod_cache-lockfile" - /** * cache_util.c */ @@ -168,8 +169,19 @@ typedef struct { /** run within the quick handler */ int quick; int quick_set; + int x_cache; + int x_cache_set; + int x_cache_detail; + int x_cache_detail_set; } cache_server_conf; +typedef struct { + int x_cache; + int x_cache_set; + int x_cache_detail; + int x_cache_detail_set; +} cache_dir_conf; + /* A linked-list of authn providers. */ typedef struct cache_provider_list cache_provider_list; diff --git a/modules/cache/mod_cache.c b/modules/cache/mod_cache.c index 438a10dd07..704968eced 100644 --- a/modules/cache/mod_cache.c +++ b/modules/cache/mod_cache.c @@ -201,6 +201,9 @@ static int cache_quick_handler(request_rec *r, int lookup) return DECLINED; } + /* we've got a cache hit! tell everyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_HIT, "cache hit"); + /* if we are a lookup, we are exiting soon one way or another; Restore * the headers. */ if (lookup) { @@ -453,6 +456,9 @@ static int cache_handler(request_rec *r) return DECLINED; } + /* we've got a cache hit! tell everyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_HIT, "cache hit"); + rv = ap_meets_conditions(r); if (rv != OK) { return rv; @@ -816,7 +822,7 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) && exp < r->request_time) { /* if a Expires header is in the past, don't cache it */ - reason = "Expires header already expired, not cacheable"; + reason = "Expires header already expired; not cacheable"; } else if (!conf->ignorequerystring && r->parsed_uri.query && exps == NULL && !ap_cache_liststr(NULL, cc_out, "max-age", NULL) && @@ -844,7 +850,7 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) /* Note: mod-include clears last_modified/expires/etags - this * is why we have an optional function for a key-gen ;-) */ - reason = "No Last-Modified, Etag, Expires, Cache-Control:max-age or Cache-Control:s-maxage headers"; + reason = "No Last-Modified; Etag; Expires; Cache-Control:max-age or Cache-Control:s-maxage headers"; } else if (r->header_only && !cache->stale_handle) { /* Forbid HEAD requests unless we have it cached already */ @@ -903,6 +909,9 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) "cache: %s not cached. Reason: %s", r->unparsed_uri, reason); + /* we've got a cache miss! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_MISS, reason); + /* remove this filter from the chain */ ap_remove_output_filter(f); @@ -1009,6 +1018,10 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) } if (rv != OK) { + /* we've got a cache miss! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_MISS, + "cache miss: create_entity failed"); + /* Caching layer declined the opportunity to cache the response */ ap_remove_output_filter(f); cache_remove_lock(conf, cache, r, cache->handle ? @@ -1211,6 +1224,17 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) "cache: attempt to remove url from cache unsuccessful."); } + /* we've got a cache conditional hit! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_REVALIDATE, + "conditional cache hit: entity refresh failed"); + + } + else { + + /* we've got a cache conditional hit! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_REVALIDATE, + "conditional cache hit: entity refreshed"); + } /* let someone else attempt to cache */ @@ -1224,12 +1248,20 @@ static int cache_save_filter(ap_filter_t *f, apr_bucket_brigade *in) ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, r->server, "cache: store_headers failed"); + /* we've got a cache miss! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_MISS, + "cache miss: store_headers failed"); + ap_remove_output_filter(f); cache_remove_lock(conf, cache, r, cache->handle ? (char *)cache->handle->cache_obj->key : NULL, NULL); return ap_pass_brigade(f->next, in); } + /* we've got a cache miss! tell anyone who cares */ + cache_run_cache_status(cache->handle, r, AP_CACHE_MISS, + "cache miss: attempting entity save"); + return cache_save_store(f, in, conf, cache); } @@ -1309,9 +1341,102 @@ static int cache_filter(ap_filter_t *f, apr_bucket_brigade *in) return ap_pass_brigade(f->next, in); } +/** + * If configured, add the status of the caching attempt to the subprocess + * environment, and if configured, to headers in the response. + * + * The status is saved below the broad category of the status (hit, miss, + * revalidate), as well as a single cache-status key. This can be used for + * conditional logging. + * + * The status is optionally saved to an X-Cache header, and the detail of + * why a particular cache entry was cached (or not cached) is optionally + * saved to an X-Cache-Detail header. This extra detail is useful for + * service developers who may need to know whether their Cache-Control headers + * are working correctly. + */ +static int cache_status(cache_handle_t *h, request_rec *r, ap_cache_status_e status, + const char *reason) +{ + cache_server_conf + *conf = + (cache_server_conf *) ap_get_module_config(r->server->module_config, + &cache_module); + + cache_dir_conf *dconf = ap_get_module_config(r->per_dir_config, &cache_module); + int x_cache = 0, x_cache_detail = 0; + + switch (status) { + case AP_CACHE_HIT: { + apr_table_setn(r->subprocess_env, AP_CACHE_HIT_ENV, reason); + break; + } + case AP_CACHE_REVALIDATE: { + apr_table_setn(r->subprocess_env, AP_CACHE_REVALIDATE_ENV, reason); + break; + } + case AP_CACHE_MISS: { + apr_table_setn(r->subprocess_env, AP_CACHE_MISS_ENV, reason); + break; + } + } + + apr_table_setn(r->subprocess_env, AP_CACHE_STATUS_ENV, reason); + + if (dconf && dconf->x_cache_set) { + x_cache = dconf->x_cache; + } + else { + x_cache = conf->x_cache; + } + if (x_cache) { + apr_table_setn(r->headers_out, "X-Cache", apr_psprintf(r->pool, "%s from %s", + status == AP_CACHE_HIT ? "HIT" : status == AP_CACHE_REVALIDATE ? + "REVALIDATE" : "MISS", r->server->server_hostname)); + } + + if (dconf && dconf->x_cache_detail_set) { + x_cache_detail = dconf->x_cache_detail; + } + else { + x_cache_detail = conf->x_cache_detail; + } + if (x_cache_detail) { + apr_table_setn(r->headers_out, "X-Cache-Detail", apr_psprintf(r->pool, + "\"%s\" from %s", reason, r->server->server_hostname)); + } + + return OK; +} + /* -------------------------------------------------------------- */ /* Setup configurable data */ +static void *create_dir_config(apr_pool_t *p, char *dummy) +{ + cache_dir_conf *dconf = apr_pcalloc(p, sizeof(cache_dir_conf)); + + dconf->x_cache = DEFAULT_X_CACHE; + dconf->x_cache_detail = DEFAULT_X_CACHE_DETAIL; + + return dconf; +} + +static void *merge_dir_config(apr_pool_t *p, void *basev, void *addv) { + cache_dir_conf *new = (cache_dir_conf *) apr_pcalloc(p, sizeof(cache_dir_conf)); + cache_dir_conf *add = (cache_dir_conf *) addv; + cache_dir_conf *base = (cache_dir_conf *) basev; + + new->x_cache = (add->x_cache_set == 0) ? base->x_cache : add->x_cache; + new->x_cache_set = add->x_cache_set || base->x_cache_set; + new->x_cache_detail = (add->x_cache_detail_set == 0) ? base->x_cache_detail + : add->x_cache_detail; + new->x_cache_detail_set = add->x_cache_detail_set + || base->x_cache_detail_set; + + return new; +} + static void * create_cache_config(apr_pool_t *p, server_rec *s) { const char *tmppath; @@ -1361,6 +1486,8 @@ static void * create_cache_config(apr_pool_t *p, server_rec *s) ps->lockpath = apr_pstrcat(p, tmppath, DEFAULT_CACHE_LOCKPATH, NULL); } ps->lockmaxage = apr_time_from_sec(DEFAULT_CACHE_MAXAGE); + ps->x_cache = DEFAULT_X_CACHE; + ps->x_cache_detail = DEFAULT_X_CACHE_DETAIL; return ps; } @@ -1435,6 +1562,14 @@ static void * merge_cache_config(apr_pool_t *p, void *basev, void *overridesv) (overrides->quick_set == 0) ? base->quick : overrides->quick; + ps->x_cache = + (overrides->x_cache_set == 0) + ? base->x_cache + : overrides->x_cache; + ps->x_cache_detail = + (overrides->x_cache_detail_set == 0) + ? base->x_cache_detail + : overrides->x_cache_detail; return ps; } @@ -1782,6 +1917,52 @@ static const char *set_cache_lock_maxage(cmd_parms *parms, void *dummy, return NULL; } +static const char *set_cache_x_cache(cmd_parms *parms, void *dummy, int flag) +{ + + if (parms->path) { + cache_dir_conf *dconf = (cache_dir_conf *)dummy; + + dconf->x_cache = flag; + dconf->x_cache_set = 1; + + } + else { + cache_server_conf *conf = + (cache_server_conf *)ap_get_module_config(parms->server->module_config, + &cache_module); + + conf->x_cache = flag; + conf->x_cache_set = 1; + + } + + return NULL; +} + +static const char *set_cache_x_cache_detail(cmd_parms *parms, void *dummy, int flag) +{ + + if (parms->path) { + cache_dir_conf *dconf = (cache_dir_conf *)dummy; + + dconf->x_cache_detail = flag; + dconf->x_cache_detail_set = 1; + + } + else { + cache_server_conf *conf = + (cache_server_conf *)ap_get_module_config(parms->server->module_config, + &cache_module); + + conf->x_cache_detail = flag; + conf->x_cache_detail_set = 1; + + } + + return NULL; +} + static int cache_post_config(apr_pool_t *p, apr_pool_t *plog, apr_pool_t *ptemp, server_rec *s) { @@ -1859,6 +2040,11 @@ static const command_rec cache_cmds[] = "temp directory."), AP_INIT_TAKE1("CacheLockMaxAge", set_cache_lock_maxage, NULL, RSRC_CONF, "Maximum age of any thundering herd lock."), + AP_INIT_FLAG("CacheHeader", set_cache_x_cache, NULL, RSRC_CONF | ACCESS_CONF, + "Add a X-Cache header to responses. Default is off."), + AP_INIT_FLAG("CacheDetailHeader", set_cache_x_cache_detail, NULL, + RSRC_CONF | ACCESS_CONF, + "Add a X-Cache-Detail header to responses. Default is off."), {NULL} }; @@ -1869,6 +2055,8 @@ static void register_hooks(apr_pool_t *p) ap_hook_quick_handler(cache_quick_handler, NULL, NULL, APR_HOOK_FIRST); /* cache handler */ ap_hook_handler(cache_handler, NULL, NULL, APR_HOOK_REALLY_FIRST); + /* cache status */ + cache_hook_cache_status(cache_status, NULL, NULL, APR_HOOK_MIDDLE); /* cache filters * XXX The cache filters need to run right after the handlers and before * any other filters. Consider creating AP_FTYPE_CACHE for this purpose. @@ -1949,10 +2137,20 @@ static void register_hooks(apr_pool_t *p) AP_DECLARE_MODULE(cache) = { STANDARD20_MODULE_STUFF, - NULL, /* create per-directory config structure */ - NULL, /* merge per-directory config structures */ + create_dir_config, /* create per-directory config structure */ + merge_dir_config, /* merge per-directory config structures */ create_cache_config, /* create per-server config structure */ merge_cache_config, /* merge per-server config structures */ cache_cmds, /* command apr_table_t */ register_hooks }; + +APR_HOOK_STRUCT( + APR_HOOK_LINK(cache_status) +) + +APR_IMPLEMENT_EXTERNAL_HOOK_RUN_ALL(cache, CACHE, int, cache_status, + (cache_handle_t *h, request_rec *r, + ap_cache_status_e status, + const char *reason), (h, r, status, reason), + OK, DECLINED) diff --git a/modules/cache/mod_cache.h b/modules/cache/mod_cache.h index 209a97b5f8..f7d3f824c2 100644 --- a/modules/cache/mod_cache.h +++ b/modules/cache/mod_cache.h @@ -29,6 +29,7 @@ #include "httpd.h" #include "apr_date.h" #include "apr_optional.h" +#include "apr_hooks.h" /* Create a set of CACHE_DECLARE(type), CACHE_DECLARE_NONSTD(type) and * CACHE_DECLARE_DATA with appropriate export and import tags for the platform @@ -106,6 +107,17 @@ typedef struct { apr_status_t (*commit_entity)(cache_handle_t *h, request_rec *r); } cache_provider; +typedef enum { + AP_CACHE_HIT, + AP_CACHE_REVALIDATE, + AP_CACHE_MISS +} ap_cache_status_e; + +#define AP_CACHE_HIT_ENV "cache-hit" +#define AP_CACHE_REVALIDATE_ENV "cache-revalidate" +#define AP_CACHE_MISS_ENV "cache-miss" +#define AP_CACHE_STATUS_ENV "cache-status" + /* cache_util.c */ /* do a HTTP/1.1 age calculation */ @@ -150,6 +162,22 @@ CACHE_DECLARE(apr_table_t *)ap_cache_cacheable_headers_out(request_rec *r); /* hooks */ + +/** + * Cache status hook. + * This hook is called as soon as the cache has made a decision as to whether + * an entity should be served from cache (hit), should be served from cache + * after a successful validation (revalidate), or served from the backend + * and potentially cached (miss). + * + * A basic implementation of this hook exists in mod_cache which writes this + * information to the subprocess environment, and optionally to request + * headers. Further implementations may add hooks as appropriate to perform + * more advanced processing, or to store statistics about the cache behaviour. + */ +APR_DECLARE_EXTERNAL_HOOK(cache, CACHE, int, cache_status, (cache_handle_t *h, + request_rec *r, ap_cache_status_e status, const char *reason)); + APR_DECLARE_OPTIONAL_FN(apr_status_t, ap_cache_generate_key, (request_rec *r, apr_pool_t*p, const char **key));