src/store_digest.cc

   1 /*
   2  * Copyright (C) 1996-2017 The Squid Software Foundation and contributors
   3  *
   4  * Squid software is distributed under GPLv2+ license and includes
   5  * contributions from numerous individuals and organizations.
   6  * Please see the COPYING and CONTRIBUTORS files for details.
   7  */
   8
   9 /* DEBUG: section 71    Store Digest Manager */
  10
  11 /*
  12  * TODO: We probably do not track all the cases when
  13  *       storeDigestNoteStoreReady() must be called; this may prevent
  14  *       storeDigestRebuild/write schedule to be activated
  15  */
  16
  17 #include "squid.h"
  18 #include "Debug.h"
  19 #include "event.h"
  20 #include "globals.h"
  21 #include "mgr/Registration.h"
  22 #include "store_digest.h"
  23
  24 #if USE_CACHE_DIGESTS
  25 #include "CacheDigest.h"
  26 #include "HttpReply.h"
  27 #include "HttpRequest.h"
  28 #include "internal.h"
  29 #include "MemObject.h"
  30 #include "PeerDigest.h"
  31 #include "refresh.h"
  32 #include "SquidConfig.h"
  33 #include "SquidTime.h"
  34 #include "Store.h"
  35 #include "StoreSearch.h"
  36 #include "util.h"
  37
  38 #include <cmath>
  39
  40 /*
  41  * local types
  42  */
  43
  44 class StoreDigestState
  45 {
  46
  47 public:
  48     StoreDigestCBlock cblock;
  49     int rebuild_lock;       /* bucket number */
  50     StoreEntry * rewrite_lock;  /* points to store entry with the digest */
  51     StoreSearchPointer theSearch;
  52     int rewrite_offset;
  53     int rebuild_count;
  54     int rewrite_count;
  55 };
  56
  57 typedef struct {
  58     int del_count;      /* #store entries deleted from store_digest */
  59     int del_lost_count;     /* #store entries not found in store_digest on delete */
  60     int add_count;      /* #store entries accepted to store_digest */
  61     int add_coll_count;     /* #accepted entries that collided with existing ones */
  62     int rej_count;      /* #store entries not accepted to store_digest */
  63     int rej_coll_count;     /* #not accepted entries that collided with existing ones */
  64 } StoreDigestStats;
  65
  66 /* local vars */
  67 static StoreDigestState sd_state;
  68 static StoreDigestStats sd_stats;
  69
  70 /* local prototypes */
  71 static void storeDigestRebuildStart(void *datanotused);
  72 static void storeDigestRebuildResume(void);
  73 static void storeDigestRebuildFinish(void);
  74 static void storeDigestRebuildStep(void *datanotused);
  75 static void storeDigestRewriteStart(void *);
  76 static void storeDigestRewriteResume(void);
  77 static void storeDigestRewriteFinish(StoreEntry * e);
  78 static EVH storeDigestSwapOutStep;
  79 static void storeDigestCBlockSwapOut(StoreEntry * e);
  80 static void storeDigestAdd(const StoreEntry *);
  81
  82 /// calculates digest capacity
  83 static uint64_t
  84 storeDigestCalcCap()
  85 {
  86     /*
  87      * To-Do: Bloom proved that the optimal filter utilization is 50% (half of
  88      * the bits are off). However, we do not have a formula to calculate the
  89      * number of _entries_ we want to pre-allocate for.
  90      */
  91     const uint64_t hi_cap = Store::Root().maxSize() / Config.Store.avgObjectSize;
  92     const uint64_t lo_cap = 1 + Store::Root().currentSize() / Config.Store.avgObjectSize;
  93     const uint64_t e_count = StoreEntry::inUseCount();
  94     uint64_t cap = e_count ? e_count : hi_cap;
  95     debugs(71, 2, "have: " << e_count << ", want " << cap <<
  96            " entries; limits: [" << lo_cap << ", " << hi_cap << "]");
  97
  98     if (cap < lo_cap)
  99         cap = lo_cap;
 100
 101     /* do not enforce hi_cap limit, average-based estimation may be wrong
 102      *if (cap > hi_cap)
 103      *  cap = hi_cap;
 104      */
 105
 106     // Bug 4534: we still have to set an upper-limit at some reasonable value though.
 107     // this matches cacheDigestCalcMaskSize doing (cap*bpe)+7 < INT_MAX
 108     const uint64_t absolute_max = (INT_MAX -8) / Config.digest.bits_per_entry;
 109     if (cap > absolute_max) {
 110         static time_t last_loud = 0;
 111         if (last_loud < squid_curtime - 86400) {
 112             debugs(71, DBG_IMPORTANT, "WARNING: Cache Digest cannot store " << cap << " entries. Limiting to " << absolute_max);
 113             last_loud = squid_curtime;
 114         } else {
 115             debugs(71, 3, "WARNING: Cache Digest cannot store " << cap << " entries. Limiting to " << absolute_max);
 116         }
 117         cap = absolute_max;
 118     }
 119
 120     return cap;
 121 }
 122 #endif /* USE_CACHE_DIGESTS */
 123
 124 void
 125 storeDigestInit(void)
 126 {
 127     Mgr::RegisterAction("store_digest", "Store Digest", storeDigestReport, 0, 1);
 128
 129 #if USE_CACHE_DIGESTS
 130     if (!Config.onoff.digest_generation) {
 131         store_digest = NULL;
 132         debugs(71, 3, "Local cache digest generation disabled");
 133         return;
 134     }
 135
 136     const uint64_t cap = storeDigestCalcCap();
 137     store_digest = new CacheDigest(cap, Config.digest.bits_per_entry);
 138     debugs(71, DBG_IMPORTANT, "Local cache digest enabled; rebuild/rewrite every " <<
 139            (int) Config.digest.rebuild_period << "/" <<
 140            (int) Config.digest.rewrite_period << " sec");
 141
 142     memset(&sd_state, 0, sizeof(sd_state));
 143 #else
 144     store_digest = NULL;
 145     debugs(71, 3, "Local cache digest is 'off'");
 146 #endif
 147 }
 148
 149 /* called when store_rebuild completes */
 150 void
 151 storeDigestNoteStoreReady(void)
 152 {
 153 #if USE_CACHE_DIGESTS
 154
 155     if (Config.onoff.digest_generation) {
 156         storeDigestRebuildStart(NULL);
 157         storeDigestRewriteStart(NULL);
 158     }
 159
 160 #endif
 161 }
 162
 163 //TODO: this seems to be dead code. Is it needed?
 164 void
 165 storeDigestDel(const StoreEntry * entry)
 166 {
 167 #if USE_CACHE_DIGESTS
 168
 169     if (!Config.onoff.digest_generation) {
 170         return;
 171     }
 172
 173     assert(entry && store_digest);
 174     debugs(71, 6, "storeDigestDel: checking entry, key: " << entry->getMD5Text());
 175
 176     if (!EBIT_TEST(entry->flags, KEY_PRIVATE)) {
 177         if (!store_digest->contains(static_cast<const cache_key *>(entry->key))) {
 178             ++sd_stats.del_lost_count;
 179             debugs(71, 6, "storeDigestDel: lost entry, key: " << entry->getMD5Text() << " url: " << entry->url()  );
 180         } else {
 181             ++sd_stats.del_count;
 182             store_digest->remove(static_cast<const cache_key *>(entry->key));
 183             debugs(71, 6, "storeDigestDel: deled entry, key: " << entry->getMD5Text());
 184         }
 185     }
 186 #endif //USE_CACHE_DIGESTS
 187 }
 188
 189 void
 190 storeDigestReport(StoreEntry * e)
 191 {
 192 #if USE_CACHE_DIGESTS
 193
 194     if (!Config.onoff.digest_generation) {
 195         return;
 196     }
 197
 198     if (store_digest) {
 199         cacheDigestReport(store_digest, "store", e);
 200         storeAppendPrintf(e, "\t added: %d rejected: %d ( %.2f %%) del-ed: %d\n",
 201                           sd_stats.add_count,
 202                           sd_stats.rej_count,
 203                           xpercent(sd_stats.rej_count, sd_stats.rej_count + sd_stats.add_count),
 204                           sd_stats.del_count);
 205         storeAppendPrintf(e, "\t collisions: on add: %.2f %% on rej: %.2f %%\n",
 206                           xpercent(sd_stats.add_coll_count, sd_stats.add_count),
 207                           xpercent(sd_stats.rej_coll_count, sd_stats.rej_count));
 208     } else {
 209         storeAppendPrintf(e, "store digest: disabled.\n");
 210     }
 211
 212 #endif //USE_CACHE_DIGESTS
 213 }
 214
 215 /*
 216  * LOCAL FUNCTIONS
 217  */
 218
 219 #if USE_CACHE_DIGESTS
 220
 221 /* should we digest this entry? used by storeDigestAdd() */
 222 static int
 223 storeDigestAddable(const StoreEntry * e)
 224 {
 225     /* add some stats! XXX */
 226
 227     debugs(71, 6, "storeDigestAddable: checking entry, key: " << e->getMD5Text());
 228
 229     /* check various entry flags (mimics StoreEntry::checkCachable XXX) */
 230
 231     if (EBIT_TEST(e->flags, KEY_PRIVATE)) {
 232         debugs(71, 6, "storeDigestAddable: NO: private key");
 233         return 0;
 234     }
 235
 236     if (EBIT_TEST(e->flags, ENTRY_NEGCACHED)) {
 237         debugs(71, 6, "storeDigestAddable: NO: negative cached");
 238         return 0;
 239     }
 240
 241     if (EBIT_TEST(e->flags, RELEASE_REQUEST)) {
 242         debugs(71, 6, "storeDigestAddable: NO: release requested");
 243         return 0;
 244     }
 245
 246     if (e->store_status == STORE_OK && EBIT_TEST(e->flags, ENTRY_BAD_LENGTH)) {
 247         debugs(71, 6, "storeDigestAddable: NO: wrong content-length");
 248         return 0;
 249     }
 250
 251     /* do not digest huge objects */
 252     if (e->swap_file_sz > (uint64_t )Config.Store.maxObjectSize) {
 253         debugs(71, 6, "storeDigestAddable: NO: too big");
 254         return 0;
 255     }
 256
 257     /* still here? check staleness */
 258     /* Note: We should use the time of the next rebuild, not (cur_time+period) */
 259     if (refreshCheckDigest(e, Config.digest.rebuild_period)) {
 260         debugs(71, 6, "storeDigestAdd: entry expires within " << Config.digest.rebuild_period << " secs, ignoring");
 261         return 0;
 262     }
 263
 264     /*
 265      * idea: how about also skipping very fresh (thus, potentially
 266      * unstable) entries? Should be configurable through
 267      * cd_refresh_pattern, of course.
 268      */
 269     /*
 270      * idea: skip objects that are going to be purged before the next
 271      * update.
 272      */
 273     return 1;
 274 }
 275
 276 static void
 277 storeDigestAdd(const StoreEntry * entry)
 278 {
 279     assert(entry && store_digest);
 280
 281     if (storeDigestAddable(entry)) {
 282         ++sd_stats.add_count;
 283
 284         if (store_digest->contains(static_cast<const cache_key *>(entry->key)))
 285             ++sd_stats.add_coll_count;
 286
 287         store_digest->add(static_cast<const cache_key *>(entry->key));
 288
 289         debugs(71, 6, "storeDigestAdd: added entry, key: " << entry->getMD5Text());
 290     } else {
 291         ++sd_stats.rej_count;
 292
 293         if (store_digest->contains(static_cast<const cache_key *>(entry->key)))
 294             ++sd_stats.rej_coll_count;
 295     }
 296 }
 297
 298 /* rebuilds digest from scratch */
 299 static void
 300 storeDigestRebuildStart(void *datanotused)
 301 {
 302     assert(store_digest);
 303     /* prevent overlapping if rebuild schedule is too tight */
 304
 305     if (sd_state.rebuild_lock) {
 306         debugs(71, DBG_IMPORTANT, "storeDigestRebuildStart: overlap detected, consider increasing rebuild period");
 307         return;
 308     }
 309
 310     sd_state.rebuild_lock = 1;
 311     debugs(71, 2, "storeDigestRebuildStart: rebuild #" << sd_state.rebuild_count + 1);
 312
 313     if (sd_state.rewrite_lock) {
 314         debugs(71, 2, "storeDigestRebuildStart: waiting for Rewrite to finish.");
 315         return;
 316     }
 317
 318     storeDigestRebuildResume();
 319 }
 320
 321 /// \returns true if we actually resized the digest
 322 static bool
 323 storeDigestResize()
 324 {
 325     const uint64_t cap = storeDigestCalcCap();
 326     assert(store_digest);
 327     uint64_t diff;
 328     if (cap > store_digest->capacity)
 329         diff = cap - store_digest->capacity;
 330     else
 331         diff = store_digest->capacity - cap;
 332     debugs(71, 2, store_digest->capacity << " -> " << cap << "; change: " <<
 333            diff << " (" << xpercentInt(diff, store_digest->capacity) << "%)" );
 334     /* avoid minor adjustments */
 335
 336     if (diff <= store_digest->capacity / 10) {
 337         debugs(71, 2, "small change, will not resize.");
 338         return false;
 339     } else {
 340         debugs(71, 2, "big change, resizing.");
 341         store_digest->updateCapacity(cap);
 342     }
 343     return true;
 344 }
 345
 346 /* called be Rewrite to push Rebuild forward */
 347 static void
 348 storeDigestRebuildResume(void)
 349 {
 350     assert(sd_state.rebuild_lock);
 351     assert(!sd_state.rewrite_lock);
 352     sd_state.theSearch = Store::Root().search();
 353     /* resize or clear */
 354
 355     if (!storeDigestResize())
 356         store_digest->clear();     /* not clean()! */
 357
 358     memset(&sd_stats, 0, sizeof(sd_stats));
 359
 360     eventAdd("storeDigestRebuildStep", storeDigestRebuildStep, NULL, 0.0, 1);
 361 }
 362
 363 /* finishes swap out sequence for the digest; schedules next rebuild */
 364 static void
 365 storeDigestRebuildFinish(void)
 366 {
 367     assert(sd_state.rebuild_lock);
 368     sd_state.rebuild_lock = 0;
 369     ++sd_state.rebuild_count;
 370     debugs(71, 2, "storeDigestRebuildFinish: done.");
 371     eventAdd("storeDigestRebuildStart", storeDigestRebuildStart, NULL, (double)
 372              Config.digest.rebuild_period, 1);
 373     /* resume pending Rewrite if any */
 374
 375     if (sd_state.rewrite_lock)
 376         storeDigestRewriteResume();
 377 }
 378
 379 /* recalculate a few hash buckets per invocation; schedules next step */
 380 static void
 381 storeDigestRebuildStep(void *datanotused)
 382 {
 383     /* TODO: call Store::Root().size() to determine this.. */
 384     int count = Config.Store.objectsPerBucket * (int) ceil((double) store_hash_buckets *
 385                 (double) Config.digest.rebuild_chunk_percentage / 100.0);
 386     assert(sd_state.rebuild_lock);
 387
 388     debugs(71, 3, "storeDigestRebuildStep: buckets: " << store_hash_buckets << " entries to check: " << count);
 389
 390     while (count-- && !sd_state.theSearch->isDone() && sd_state.theSearch->next())
 391         storeDigestAdd(sd_state.theSearch->currentItem());
 392
 393     /* are we done ? */
 394     if (sd_state.theSearch->isDone())
 395         storeDigestRebuildFinish();
 396     else
 397         eventAdd("storeDigestRebuildStep", storeDigestRebuildStep, NULL, 0.0, 1);
 398 }
 399
 400 /* starts swap out sequence for the digest */
 401 static void
 402 storeDigestRewriteStart(void *datanotused)
 403 {
 404     RequestFlags flags;
 405     char *url;
 406     StoreEntry *e;
 407
 408     assert(store_digest);
 409     /* prevent overlapping if rewrite schedule is too tight */
 410
 411     if (sd_state.rewrite_lock) {
 412         debugs(71, DBG_IMPORTANT, "storeDigestRewrite: overlap detected, consider increasing rewrite period");
 413         return;
 414     }
 415
 416     debugs(71, 2, "storeDigestRewrite: start rewrite #" << sd_state.rewrite_count + 1);
 417     /* make new store entry */
 418     url = internalLocalUri("/squid-internal-periodic/", SBuf(StoreDigestFileName));
 419     flags.cachable = true;
 420     e = storeCreateEntry(url, url, flags, Http::METHOD_GET);
 421     assert(e);
 422     sd_state.rewrite_lock = e;
 423     debugs(71, 3, "storeDigestRewrite: url: " << url << " key: " << e->getMD5Text());
 424     HttpRequest *req = HttpRequest::CreateFromUrl(url);
 425     e->mem_obj->request = req;
 426     HTTPMSGLOCK(e->mem_obj->request);
 427     /* wait for rebuild (if any) to finish */
 428
 429     if (sd_state.rebuild_lock) {
 430         debugs(71, 2, "storeDigestRewriteStart: waiting for rebuild to finish.");
 431         return;
 432     }
 433
 434     storeDigestRewriteResume();
 435 }
 436
 437 static void
 438 storeDigestRewriteResume(void)
 439 {
 440     StoreEntry *e;
 441
 442     assert(sd_state.rewrite_lock);
 443     assert(!sd_state.rebuild_lock);
 444     e = sd_state.rewrite_lock;
 445     sd_state.rewrite_offset = 0;
 446     EBIT_SET(e->flags, ENTRY_SPECIAL);
 447     /* setting public key will purge old digest entry if any */
 448     e->setPublicKey();
 449     /* fake reply */
 450     HttpReply *rep = new HttpReply;
 451     rep->setHeaders(Http::scOkay, "Cache Digest OK",
 452                     "application/cache-digest", (store_digest->mask_size + sizeof(sd_state.cblock)),
 453                     squid_curtime, (squid_curtime + Config.digest.rewrite_period) );
 454     debugs(71, 3, "storeDigestRewrite: entry expires on " << rep->expires <<
 455            " (" << std::showpos << (int) (rep->expires - squid_curtime) << ")");
 456     e->buffer();
 457     e->replaceHttpReply(rep);
 458     storeDigestCBlockSwapOut(e);
 459     e->flush();
 460     eventAdd("storeDigestSwapOutStep", storeDigestSwapOutStep, sd_state.rewrite_lock, 0.0, 1, false);
 461 }
 462
 463 /* finishes swap out sequence for the digest; schedules next rewrite */
 464 static void
 465 storeDigestRewriteFinish(StoreEntry * e)
 466 {
 467     assert(e == sd_state.rewrite_lock);
 468     e->complete();
 469     e->timestampsSet();
 470     debugs(71, 2, "storeDigestRewriteFinish: digest expires at " << e->expires <<
 471            " (" << std::showpos << (int) (e->expires - squid_curtime) << ")");
 472     /* is this the write order? @?@ */
 473     e->mem_obj->unlinkRequest();
 474     e->unlock("storeDigestRewriteFinish");
 475     sd_state.rewrite_lock = NULL;
 476     ++sd_state.rewrite_count;
 477     eventAdd("storeDigestRewriteStart", storeDigestRewriteStart, NULL, (double)
 478              Config.digest.rewrite_period, 1);
 479     /* resume pending Rebuild if any */
 480
 481     if (sd_state.rebuild_lock)
 482         storeDigestRebuildResume();
 483 }
 484
 485 /* swaps out one digest "chunk" per invocation; schedules next swap out */
 486 static void
 487 storeDigestSwapOutStep(void *data)
 488 {
 489     StoreEntry *e = static_cast<StoreEntry *>(data);
 490     int chunk_size = Config.digest.swapout_chunk_size;
 491     assert(e == sd_state.rewrite_lock);
 492     assert(e);
 493     /* _add_ check that nothing bad happened while we were waiting @?@ @?@ */
 494
 495     if (static_cast<uint32_t>(sd_state.rewrite_offset + chunk_size) > store_digest->mask_size)
 496         chunk_size = store_digest->mask_size - sd_state.rewrite_offset;
 497
 498     e->append(store_digest->mask + sd_state.rewrite_offset, chunk_size);
 499
 500     debugs(71, 3, "storeDigestSwapOutStep: size: " << store_digest->mask_size <<
 501            " offset: " << sd_state.rewrite_offset << " chunk: " <<
 502            chunk_size << " bytes");
 503
 504     sd_state.rewrite_offset += chunk_size;
 505
 506     /* are we done ? */
 507     if (static_cast<uint32_t>(sd_state.rewrite_offset) >= store_digest->mask_size)
 508         storeDigestRewriteFinish(e);
 509     else
 510         eventAdd("storeDigestSwapOutStep", storeDigestSwapOutStep, data, 0.0, 1, false);
 511 }
 512
 513 static void
 514 storeDigestCBlockSwapOut(StoreEntry * e)
 515 {
 516     memset(&sd_state.cblock, 0, sizeof(sd_state.cblock));
 517     sd_state.cblock.ver.current = htons(CacheDigestVer.current);
 518     sd_state.cblock.ver.required = htons(CacheDigestVer.required);
 519     sd_state.cblock.capacity = htonl(store_digest->capacity);
 520     sd_state.cblock.count = htonl(store_digest->count);
 521     sd_state.cblock.del_count = htonl(store_digest->del_count);
 522     sd_state.cblock.mask_size = htonl(store_digest->mask_size);
 523     sd_state.cblock.bits_per_entry = Config.digest.bits_per_entry;
 524     sd_state.cblock.hash_func_count = (unsigned char) CacheDigestHashFuncCount;
 525     e->append((char *) &sd_state.cblock, sizeof(sd_state.cblock));
 526 }
 527
 528 #endif /* USE_CACHE_DIGESTS */
 529