src/store_digest.cc

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