src/store_digest.cc

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