From: rousskov <> Date: Sat, 17 Oct 1998 10:34:08 +0000 (+0000) Subject: - eliminated refreshWhen() which was out-of-sync with refreshCheck() X-Git-Tag: SQUID_3_0_PRE1~2565 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=829a93575aa5376b8dbc524951cef2db53f39e6c;p=thirdparty%2Fsquid.git - eliminated refreshWhen() which was out-of-sync with refreshCheck() potentially causing under-utilized cache digests - maintain refreshCheck statistics on per-protocol basis so we can tell why ICP or Digests return too many misses, etc. --- diff --git a/ChangeLog b/ChangeLog index 7cc370d2e8..2894cf7094 100644 --- a/ChangeLog +++ b/ChangeLog @@ -14,6 +14,10 @@ Changes to Squid-2.1 (): bugs. - Configurable handling of whitespace in request URI's. See 'uri_whitespace' in squid.conf. + - Eliminated refreshWhen() which was out-of-sync with refreshCheck() + potentially causing under-utilized cache digests + - Maintain refreshCheck statistics on per-protocol basis so we + can tell why ICP or Digests return too many misses, etc. Changes to Squid-2.0 (October 2, 1998): diff --git a/src/client_side.cc b/src/client_side.cc index 9324e93e86..c4de90118b 100644 --- a/src/client_side.cc +++ b/src/client_side.cc @@ -1,6 +1,6 @@ /* - * $Id: client_side.cc,v 1.415 1998/10/16 19:19:29 wessels Exp $ + * $Id: client_side.cc,v 1.416 1998/10/17 04:34:09 rousskov Exp $ * * DEBUG: section 33 Client-side Routines * AUTHOR: Duane Wessels @@ -1197,7 +1197,7 @@ clientCacheHit(void *data, char *buf, ssize_t size) if (e->mem_status == IN_MEMORY) http->log_type = LOG_TCP_MEM_HIT; clientSendMoreData(data, buf, size); - } else if (refreshCheck(e, r, 0) && !http->flags.internal) { + } else if (refreshCheckHTTP(e, r) && !http->flags.internal) { /* * We hold a stale copy; it needs to be validated */ diff --git a/src/icp_v2.cc b/src/icp_v2.cc index df2fc986b0..c2b39b99d7 100644 --- a/src/icp_v2.cc +++ b/src/icp_v2.cc @@ -1,6 +1,6 @@ /* - * $Id: icp_v2.cc,v 1.54 1998/10/13 20:35:55 wessels Exp $ + * $Id: icp_v2.cc,v 1.55 1998/10/17 04:34:10 rousskov Exp $ * * DEBUG: section 12 Internet Cache Protocol * AUTHOR: Duane Wessels @@ -173,7 +173,7 @@ icpCheckUdpHit(StoreEntry * e, request_t * request) return 0; if (Config.onoff.icp_hit_stale) return 1; - if (refreshCheck(e, request, 30)) + if (refreshCheckICP(e, request)) return 0; return 1; } diff --git a/src/protos.h b/src/protos.h index 1a6a33198c..1265d1caba 100644 --- a/src/protos.h +++ b/src/protos.h @@ -1,6 +1,6 @@ /* - * $Id: protos.h,v 1.280 1998/10/16 20:02:47 wessels Exp $ + * $Id: protos.h,v 1.281 1998/10/17 04:34:11 rousskov Exp $ * * * SQUID Internet Object Cache http://squid.nlanr.net/Squid/ @@ -643,8 +643,9 @@ extern void authenticateInit(void); extern void authenticateShutdown(void); extern void refreshAddToList(const char *, int, time_t, int, time_t); -extern int refreshCheck(const StoreEntry *, request_t *, time_t delta); -extern time_t refreshWhen(const StoreEntry * entry); +extern int refreshCheckHTTP(const StoreEntry *, request_t *); +extern int refreshCheckICP(const StoreEntry *, request_t *); +extern int refreshCheckDigest(const StoreEntry *, time_t delta); extern time_t getMaxAge(const char *url); extern void refreshInit(void); diff --git a/src/refresh.cc b/src/refresh.cc index b931ae7caf..d0bf14ef0e 100644 --- a/src/refresh.cc +++ b/src/refresh.cc @@ -1,7 +1,7 @@ /* - * $Id: refresh.cc,v 1.36 1998/09/19 17:06:09 wessels Exp $ + * $Id: refresh.cc,v 1.37 1998/10/17 04:34:12 rousskov Exp $ * * DEBUG: section 22 Refresh Calculation * AUTHOR: Harvest Derived @@ -40,7 +40,10 @@ #include "squid.h" -struct { +typedef enum { rcHTTP, rcICP, rcCDigest, rcCount } refreshCountsEnum; + +static struct RefreshCounts { + const char *proto; int total; int revalidate_stale; int request_max_age_stale; @@ -51,7 +54,7 @@ struct { int last_modified_factor_stale; int conf_min_age_fresh; int default_stale; -} refreshCounts; +} refreshCounts[rcCount]; /* * Defaults: @@ -89,15 +92,16 @@ refreshUncompiledPattern(const char *pat) return NULL; } -/* - * refreshCheck(): - * return 1 if its time to revalidate this entry, 0 otherwise +/* return 1 if the entry must be revalidated within delta seconds + * 0 otherwise + * + * note: request maybe null (e.g. for cache digests build) */ -int -refreshCheck(const StoreEntry * entry, request_t * request, time_t delta) +static int +refreshCheck(const StoreEntry * entry, request_t * request, time_t delta, struct RefreshCounts *rc) { const refresh_t *R; - const char *uri; + const char *uri = NULL; time_t min = REFRESH_DEFAULT_MIN; double pct = REFRESH_DEFAULT_PCT; time_t max = REFRESH_DEFAULT_MAX; @@ -107,22 +111,24 @@ refreshCheck(const StoreEntry * entry, request_t * request, time_t delta) int reload_into_ims = 0; int ignore_reload = 0; #endif - const char *pattern = "."; + const char *pattern = ""; time_t age; double factor; time_t check_time = squid_curtime + delta; if (entry->mem_obj) uri = entry->mem_obj->url; else + if (request) uri = urlCanonical(request); - debug(22, 3) ("refreshCheck: '%s'\n", uri); - refreshCounts.total++; + + debug(22, 3) ("refreshCheck(%s): '%s'\n", rc->proto, uri ? uri : ""); + rc->total++; if (EBIT_TEST(entry->flags, ENTRY_REVALIDATE)) { debug(22, 3) ("refreshCheck: YES: Required Authorization\n"); - refreshCounts.revalidate_stale++; + rc->revalidate_stale++; return 1; } - if ((R = refreshLimits(uri))) { + if ((R = uri ? refreshLimits(uri) : refreshUncompiledPattern("."))) { min = R->min; pct = R->pct; max = R->max; @@ -144,28 +150,31 @@ refreshCheck(const StoreEntry * entry, request_t * request, time_t delta) debug(22, 3) ("refreshCheck: age = %d\n", (int) age); debug(22, 3) ("\tcheck_time:\t%s\n", mkrfc1123(check_time)); debug(22, 3) ("\tentry->timestamp:\t%s\n", mkrfc1123(entry->timestamp)); + /* request-specific checks */ + if (request) { #if HTTP_VIOLATIONS - if (request->flags.nocache_hack) { - if (ignore_reload) { - /* The clients no-cache header is ignored */ - debug(22, 3) ("refreshCheck: MAYBE: ignore-reload\n"); - } else if (reload_into_ims) { - /* The clients no-cache header is changed into a IMS query */ - debug(22, 3) ("refreshCheck: YES: reload-into-ims\n"); - return 1; - } else { - /* The clients no-cache header is not overridden on this request */ - debug(22, 3) ("refreshCheck: YES: client reload\n"); - request->flags.nocache = 1; - return 1; + if (request->flags.nocache_hack) { + if (ignore_reload) { + /* The clients no-cache header is ignored */ + debug(22, 3) ("refreshCheck: MAYBE: ignore-reload\n"); + } else if (reload_into_ims) { + /* The clients no-cache header is changed into a IMS query */ + debug(22, 3) ("refreshCheck: YES: reload-into-ims\n"); + return 1; + } else { + /* The clients no-cache header is not overridden on this request */ + debug(22, 3) ("refreshCheck: YES: client reload\n"); + request->flags.nocache = 1; + return 1; + } } - } #endif - if (request->max_age > -1) { - if (age > request->max_age) { - debug(22, 3) ("refreshCheck: YES: age > client-max-age\n"); - refreshCounts.request_max_age_stale++; - return 1; + if (request->max_age > -1) { + if (age > request->max_age) { + debug(22, 3) ("refreshCheck: YES: age > client-max-age\n"); + rc->request_max_age_stale++; + return 1; + } } } #if HTTP_VIOLATIONS @@ -177,17 +186,17 @@ refreshCheck(const StoreEntry * entry, request_t * request, time_t delta) if (entry->expires > -1) { if (entry->expires <= check_time) { debug(22, 3) ("refreshCheck: YES: expires <= curtime\n"); - refreshCounts.response_expires_stale++; + rc->response_expires_stale++; return 1; } else { debug(22, 3) ("refreshCheck: NO: expires > curtime\n"); - refreshCounts.response_expires_fresh++; + rc->response_expires_fresh++; return 0; } } if (age > max) { debug(22, 3) ("refreshCheck: YES: age > max\n"); - refreshCounts.conf_max_age_stale++; + rc->conf_max_age_stale++; return 1; } #if HTTP_VIOLATIONS @@ -201,77 +210,40 @@ refreshCheck(const StoreEntry * entry, request_t * request, time_t delta) debug(22, 3) ("refreshCheck: factor = %f\n", factor); if (factor < pct) { debug(22, 3) ("refreshCheck: NO: factor < pct\n"); - refreshCounts.last_modified_factor_fresh++; + rc->last_modified_factor_fresh++; return 0; } else { debug(22, 3) ("refreshCheck: YES: factor >= pct\n"); - refreshCounts.last_modified_factor_stale++; + rc->last_modified_factor_stale++; return 1; } } if (age <= min) { debug(22, 3) ("refreshCheck: NO: age < min\n"); - refreshCounts.conf_min_age_fresh++; + rc->conf_min_age_fresh++; return 0; } debug(22, 3) ("refreshCheck: YES: default stale\n"); - refreshCounts.default_stale++; + rc->default_stale++; return 1; } -/* returns an approximate time when refreshCheck() may return true */ -time_t -refreshWhen(const StoreEntry * entry) -{ - const refresh_t *R; - time_t refresh_time = squid_curtime; - time_t min = REFRESH_DEFAULT_MIN; - time_t max = REFRESH_DEFAULT_MAX; - double pct = REFRESH_DEFAULT_PCT; - const char *pattern = "."; - if (entry->mem_obj) { - assert(entry->mem_obj->url); - debug(22, 3) ("refreshWhen: key '%s'\n", storeKeyText(entry->key)); - debug(22, 3) ("refreshWhen: url '%s'\n", entry->mem_obj->url); - if (EBIT_TEST(entry->flags, ENTRY_REVALIDATE)) { - debug(22, 3) ("refreshWhen: NOW: Required Authorization\n"); - return refresh_time; - } - debug(22, 3) ("refreshWhen: entry: exp: %d, tstamp: %d, lmt: %d\n", - entry->expires, entry->timestamp, entry->lastmod); - R = refreshLimits(entry->mem_obj->url); - } else { - R = refreshUncompiledPattern("."); - } - if (R != NULL) { - min = R->min; - max = R->max; - pct = R->pct; - pattern = R->pattern; - } - debug(22, 3) ("refreshWhen: Matched '%s %d %d%% %d'\n", - pattern, (int) min, (int) (100.0 * pct), (int) max); - /* convert to absolute numbers */ - min += entry->timestamp; - max += entry->timestamp; - if (-1 < entry->expires) { - debug(22, 3) ("refreshWhen: expires set\n"); - refresh_time = entry->expires; - } else if (entry->timestamp <= entry->lastmod) { - debug(22, 3) ("refreshWhen: lastvalid <= lastmod\n"); - refresh_time = squid_curtime; - } else { - refresh_time = (entry->timestamp - entry->lastmod) * pct + entry->timestamp; - debug(22, 3) ("refreshWhen: using refresh pct\n"); - } - /* take min/max into account, max takes priority over min */ - if (refresh_time < min) - refresh_time = min; - if (refresh_time > max) - refresh_time = max; - debug(22, 3) ("refreshWhen: answer: %d (in %d secs)\n", - refresh_time, (int) (refresh_time - squid_curtime)); - return refresh_time; +/* refreshCheck... functions below are protocol-specific wrappers around + * refreshCheck() function above */ + +int +refreshCheckHTTP(const StoreEntry * entry, request_t * request) { + return refreshCheck(entry, request, 0, refreshCounts + rcHTTP); +} + +int +refreshCheckICP(const StoreEntry * entry, request_t * request) { + return refreshCheck(entry, request, 30, refreshCounts + rcICP); +} + +int +refreshCheckDigest(const StoreEntry * entry, time_t delta) { + return refreshCheck(entry, NULL, delta, refreshCounts + rcCDigest); } time_t @@ -285,34 +257,67 @@ getMaxAge(const char *url) return REFRESH_DEFAULT_MAX; } +static void +refreshCountsStats(StoreEntry * sentry, struct RefreshCounts *rc) +{ + storeAppendPrintf(sentry, "\n\n%s histogram:\n", rc->proto); + storeAppendPrintf(sentry, "Category\tCount\t%%Total\n"); + + storeAppendPrintf(sentry, "revalidate_stale\t%6d\t%6.2f\n", + rc->revalidate_stale, xpercent(rc->revalidate_stale, rc->total)); + storeAppendPrintf(sentry, "request_max_age_stale\t%6d\t%6.2f\n", + rc->request_max_age_stale, xpercent(rc->revalidate_stale, rc->total)); + storeAppendPrintf(sentry, "response_expires_stale\t%6d\t%6.2f\n", + rc->response_expires_stale, xpercent(rc->revalidate_stale, rc->total)); + storeAppendPrintf(sentry, "response_expires_fresh\t%6d\t%6.2f\n", + rc->response_expires_fresh, xpercent(rc->response_expires_fresh, rc->total)); + storeAppendPrintf(sentry, "conf_max_age_stale\t%6d\t%6.2f\n", + rc->conf_max_age_stale, xpercent(rc->conf_max_age_stale, rc->total)); + storeAppendPrintf(sentry, "last_modified_factor_fresh\t%6d\t%6.2f\n", + rc->last_modified_factor_fresh, xpercent(rc->last_modified_factor_fresh, rc->total)); + storeAppendPrintf(sentry, "last_modified_factor_stale\t%6d\t%6.2f\n", + rc->last_modified_factor_stale, xpercent(rc->last_modified_factor_stale, rc->total)); + storeAppendPrintf(sentry, "conf_min_age_fresh\t%6d\t%6.2f\n", + rc->conf_min_age_fresh, xpercent(rc->conf_min_age_fresh, rc->total)); + storeAppendPrintf(sentry, "default_stale\t%6d\t%6.2f\n", + rc->default_stale, xpercent(rc->default_stale, rc->total)); + storeAppendPrintf(sentry, "total\t%6d\t%6.2f\n", + rc->total, xpercent(rc->total, rc->total)); +} + static void refreshStats(StoreEntry * sentry) { - storeAppendPrintf(sentry, "refreshCounts.total\t%d\n", - refreshCounts.total); - storeAppendPrintf(sentry, "refreshCounts.revalidate_stale\t%d\n", - refreshCounts.revalidate_stale); - storeAppendPrintf(sentry, "refreshCounts.request_max_age_stale\t%d\n", - refreshCounts.request_max_age_stale); - storeAppendPrintf(sentry, "refreshCounts.response_expires_stale\t%d\n", - refreshCounts.response_expires_stale); - storeAppendPrintf(sentry, "refreshCounts.response_expires_fresh\t%d\n", - refreshCounts.response_expires_fresh); - storeAppendPrintf(sentry, "refreshCounts.conf_max_age_stale\t%d\n", - refreshCounts.conf_max_age_stale); - storeAppendPrintf(sentry, "refreshCounts.last_modified_factor_fresh\t%d\n", - refreshCounts.last_modified_factor_fresh); - storeAppendPrintf(sentry, "refreshCounts.last_modified_factor_stale\t%d\n", - refreshCounts.last_modified_factor_stale); - storeAppendPrintf(sentry, "refreshCounts.conf_min_age_fresh\t%d\n", - refreshCounts.conf_min_age_fresh); - storeAppendPrintf(sentry, "refreshCounts.default_stale\t%d\n", - refreshCounts.default_stale); + int i; + int total = 0; + + /* get total usage count */ + for (i = 0; i < rcCount; ++i) + total += refreshCounts[i].total; + + /* protocol usage histogram */ + storeAppendPrintf(sentry, "\nRefreshCheck calls per protocol\n\n"); + storeAppendPrintf(sentry, "Protocol\t#Calls\t%%Calls\n"); + for (i = 0; i < rcCount; ++i) + storeAppendPrintf(sentry, "%10s\t%6d\t%6.2f\n", + refreshCounts[i].proto, + refreshCounts[i].total, + xpercent(refreshCounts[i].total, total)); + + /* per protocol histograms */ + storeAppendPrintf(sentry, "\n\nRefreshCheck histograms for various protocols\n"); + for (i = 0; i < rcCount; ++i) + refreshCountsStats(sentry, refreshCounts + i); } void -refreshInit(void) +refreshInit() { + memset(refreshCounts, 0, sizeof(refreshCounts)); + refreshCounts[rcHTTP].proto = "HTTP"; + refreshCounts[rcICP].proto = "ICP"; + refreshCounts[rcCDigest].proto = "Cache Digests"; + cachemgrRegister("refresh", "Refresh Algorithm Statistics", refreshStats, diff --git a/src/store_digest.cc b/src/store_digest.cc index dcc09ef83a..6b6d820f9c 100644 --- a/src/store_digest.cc +++ b/src/store_digest.cc @@ -1,5 +1,5 @@ /* - * $Id: store_digest.cc,v 1.28 1998/09/19 17:06:13 wessels Exp $ + * $Id: store_digest.cc,v 1.29 1998/10/17 04:34:12 rousskov Exp $ * * DEBUG: section 71 Store Digest Manager * AUTHOR: Alex Rousskov @@ -189,13 +189,11 @@ storeDigestAdd(const StoreEntry * entry) storeKeyText(entry->key)); /* only public entries are digested */ if (!EBIT_TEST(entry->flags, KEY_PRIVATE)) { - const time_t refresh = refreshWhen(entry); - debug(71, 6) ("storeDigestAdd: entry expires in %d secs\n", - (int) (refresh - squid_curtime)); /* if expires too soon, ignore */ - /* Note: We should use the time of the next rebuild, not cur_time @?@ */ - if (refresh <= squid_curtime + StoreDigestRebuildPeriod) { - debug(71, 6) ("storeDigestAdd: entry expires too early, ignoring\n"); + /* Note: We should use the time of the next rebuild, not (cur_time+period) */ + if (refreshCheckDigest(entry, StoreDigestRebuildPeriod)) { + debug(71, 6) ("storeDigestAdd: entry expires within %d secs, ignoring\n", + StoreDigestRebuildPeriod); } else { good_entry = 1; }