src/store_rebuild.cc

   1
   2 /*
   3  * $Id$
   4  *
   5  * DEBUG: section 20    Store Rebuild Routines
   6  * AUTHOR: Duane Wessels
   7  *
   8  * SQUID Web Proxy Cache          http://www.squid-cache.org/
   9  * ----------------------------------------------------------
  10  *
  11  *  Squid is the result of efforts by numerous individuals from
  12  *  the Internet community; see the CONTRIBUTORS file for full
  13  *  details.   Many organizations have provided support for Squid's
  14  *  development; see the SPONSORS file for full details.  Squid is
  15  *  Copyrighted (C) 2001 by the Regents of the University of
  16  *  California; see the COPYRIGHT file for full details.  Squid
  17  *  incorporates software developed and/or copyrighted by other
  18  *  sources; see the CREDITS file for full details.
  19  *
  20  *  This program is free software; you can redistribute it and/or modify
  21  *  it under the terms of the GNU General Public License as published by
  22  *  the Free Software Foundation; either version 2 of the License, or
  23  *  (at your option) any later version.
  24  *
  25  *  This program is distributed in the hope that it will be useful,
  26  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
  27  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  28  *  GNU General Public License for more details.
  29  *
  30  *  You should have received a copy of the GNU General Public License
  31  *  along with this program; if not, write to the Free Software
  32  *  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
  33  *
  34  */
  35
  36 #include "squid.h"
  37 #include "event.h"
  38 #include "Store.h"
  39 #include "SwapDir.h"
  40 #include "StoreSearch.h"
  41 #include "SquidTime.h"
  42
  43 static struct _store_rebuild_data counts;
  44
  45 static struct timeval rebuild_start;
  46 static void storeCleanup(void *);
  47
  48 typedef struct {
  49     /* total number of "swap.state" entries that will be read */
  50     int total;
  51     /* number of entries read so far */
  52     int scanned;
  53 } store_rebuild_progress;
  54
  55 static store_rebuild_progress *RebuildProgress = NULL;
  56
  57 static int
  58 storeCleanupDoubleCheck(StoreEntry * e)
  59 {
  60     SwapDir *SD = dynamic_cast<SwapDir *>(INDEXSD(e->swap_dirn));
  61     return (SD->doubleCheck(*e));
  62 }
  63
  64 static void
  65 storeCleanup(void *datanotused)
  66 {
  67     static int store_errors = 0;
  68     static StoreSearchPointer currentSearch;
  69     static int validated = 0;
  70
  71     if (currentSearch == NULL || currentSearch->isDone())
  72         currentSearch = Store::Root().search(NULL, NULL);
  73
  74     size_t statCount = 500;
  75
  76     while (statCount-- && !currentSearch->isDone() && currentSearch->next()) {
  77         StoreEntry *e;
  78
  79         e = currentSearch->currentItem();
  80
  81         if (EBIT_TEST(e->flags, ENTRY_VALIDATED))
  82             continue;
  83
  84         /*
  85          * Calling StoreEntry->release() has no effect because we're
  86          * still in 'store_rebuilding' state
  87          */
  88         if (e->swap_filen < 0)
  89             continue;
  90
  91         if (opt_store_doublecheck)
  92             if (storeCleanupDoubleCheck(e))
  93                 store_errors++;
  94
  95         EBIT_SET(e->flags, ENTRY_VALIDATED);
  96
  97         /*
  98          * Only set the file bit if we know its a valid entry
  99          * otherwise, set it in the validation procedure
 100          */
 101
 102         if ((++validated & 0x3FFFF) == 0)
 103             /* TODO format the int with with a stream operator */
 104             debugs(20, 1, "  " << validated << " Entries Validated so far.");
 105     }
 106
 107     if (currentSearch->isDone()) {
 108         debugs(20, 1, "  Completed Validation Procedure");
 109         debugs(20, 1, "  Validated " << validated << " Entries");
 110         debugs(20, 1, "  store_swap_size = " << Store::Root().currentSize() / 1024.0 << " KB");
 111         StoreController::store_dirs_rebuilding--;
 112         assert(0 == StoreController::store_dirs_rebuilding);
 113
 114         if (opt_store_doublecheck)
 115             assert(store_errors == 0);
 116
 117         if (store_digest)
 118             storeDigestNoteStoreReady();
 119
 120         currentSearch = NULL;
 121     } else
 122         eventAdd("storeCleanup", storeCleanup, NULL, 0.0, 1);
 123 }
 124
 125 /* meta data recreated from disk image in swap directory */
 126 void
 127
 128 storeRebuildComplete(struct _store_rebuild_data *dc)
 129 {
 130     double dt;
 131     counts.objcount += dc->objcount;
 132     counts.expcount += dc->expcount;
 133     counts.scancount += dc->scancount;
 134     counts.clashcount += dc->clashcount;
 135     counts.dupcount += dc->dupcount;
 136     counts.cancelcount += dc->cancelcount;
 137     counts.invalid += dc->invalid;
 138     counts.badflags += dc->badflags;
 139     counts.bad_log_op += dc->bad_log_op;
 140     counts.zero_object_sz += dc->zero_object_sz;
 141     /*
 142      * When store_dirs_rebuilding == 1, it means we are done reading
 143      * or scanning all cache_dirs.  Now report the stats and start
 144      * the validation (storeCleanup()) thread.
 145      */
 146
 147     if (StoreController::store_dirs_rebuilding > 1)
 148         return;
 149
 150     dt = tvSubDsec(rebuild_start, current_time);
 151
 152     debugs(20, 1, "Finished rebuilding storage from disk.");
 153     debugs(20, 1, "  " << std::setw(7) << counts.scancount  << " Entries scanned");
 154     debugs(20, 1, "  " << std::setw(7) << counts.invalid  << " Invalid entries.");
 155     debugs(20, 1, "  " << std::setw(7) << counts.badflags  << " With invalid flags.");
 156     debugs(20, 1, "  " << std::setw(7) << counts.objcount  << " Objects loaded.");
 157     debugs(20, 1, "  " << std::setw(7) << counts.expcount  << " Objects expired.");
 158     debugs(20, 1, "  " << std::setw(7) << counts.cancelcount  << " Objects cancelled.");
 159     debugs(20, 1, "  " << std::setw(7) << counts.dupcount  << " Duplicate URLs purged.");
 160     debugs(20, 1, "  " << std::setw(7) << counts.clashcount  << " Swapfile clashes avoided.");
 161     debugs(20, 1, "  Took "<< std::setw(3)<< std::setprecision(2) << dt << " seconds ("<< std::setw(6) <<
 162            ((double) counts.objcount / (dt > 0.0 ? dt : 1.0)) << " objects/sec).");
 163     debugs(20, 1, "Beginning Validation Procedure");
 164
 165     eventAdd("storeCleanup", storeCleanup, NULL, 0.0, 1);
 166
 167     xfree(RebuildProgress);
 168
 169     RebuildProgress = NULL;
 170 }
 171
 172 /*
 173  * this is ugly.  We don't actually start any rebuild threads here,
 174  * but only initialize counters, etc.  The rebuild threads are
 175  * actually started by the filesystem "fooDirInit" function.
 176  */
 177 void
 178 storeRebuildStart(void)
 179 {
 180     memset(&counts, '\0', sizeof(counts));
 181     rebuild_start = current_time;
 182     /*
 183      * Note: store_dirs_rebuilding is initialized to 1.
 184      *
 185      * When we parse the configuration and construct each swap dir,
 186      * the construction of that raises the rebuild count.
 187      *
 188      * This prevents us from trying to write clean logs until we
 189      * finished rebuilding - including after a reconfiguration that opens an
 190      * existing swapdir.  The corresponding decrement * occurs in
 191      * storeCleanup(), when it is finished.
 192      */
 193     RebuildProgress = (store_rebuild_progress *)xcalloc(Config.cacheSwap.n_configured,
 194                       sizeof(store_rebuild_progress));
 195 }
 196
 197 /*
 198  * A fs-specific rebuild procedure periodically reports its
 199  * progress.
 200  */
 201 void
 202 storeRebuildProgress(int sd_index, int total, int sofar)
 203 {
 204     static time_t last_report = 0;
 205     double n = 0.0;
 206     double d = 0.0;
 207
 208     if (sd_index < 0)
 209         return;
 210
 211     if (sd_index >= Config.cacheSwap.n_configured)
 212         return;
 213
 214     if (NULL == RebuildProgress)
 215         return;
 216
 217     RebuildProgress[sd_index].total = total;
 218
 219     RebuildProgress[sd_index].scanned = sofar;
 220
 221     if (squid_curtime - last_report < 15)
 222         return;
 223
 224     for (sd_index = 0; sd_index < Config.cacheSwap.n_configured; sd_index++) {
 225         n += (double) RebuildProgress[sd_index].scanned;
 226         d += (double) RebuildProgress[sd_index].total;
 227     }
 228
 229     debugs(20, 1, "Store rebuilding is "<< std::setw(4)<< std::setprecision(2) << 100.0 * n / d << "% complete");
 230     last_report = squid_curtime;
 231 }
 232
 233 #include "fde.h"
 234 #include "StoreMetaUnpacker.h"
 235 #include "StoreMeta.h"
 236 #include "Generic.h"
 237
 238 struct InitStoreEntry : public unary_function<StoreMeta, void> {
 239     InitStoreEntry(StoreEntry *anEntry, cache_key *aKey):what(anEntry),index(aKey) {}
 240
 241     void operator()(StoreMeta const &x) {
 242         switch (x.getType()) {
 243
 244         case STORE_META_KEY:
 245             assert(x.length == SQUID_MD5_DIGEST_LENGTH);
 246             memcpy(index, x.value, SQUID_MD5_DIGEST_LENGTH);
 247             break;
 248
 249         case STORE_META_STD:
 250             struct old_metahdr {
 251                 time_t timestamp;
 252                 time_t lastref;
 253                 time_t expires;
 254                 time_t lastmod;
 255                 size_t swap_file_sz;
 256                 uint16_t refcount;
 257                 uint16_t flags;
 258             } *tmp;
 259             tmp = (struct old_metahdr *)x.value;
 260             assert(x.length == STORE_HDR_METASIZE_OLD);
 261             what->timestamp = tmp->timestamp;
 262             what->lastref = tmp->lastref;
 263             what->expires = tmp->expires;
 264             what->lastmod = tmp->lastmod;
 265             what->swap_file_sz = tmp->swap_file_sz;
 266             what->refcount = tmp->refcount;
 267             what->flags = tmp->flags;
 268             break;
 269
 270         case STORE_META_STD_LFS:
 271             assert(x.length == STORE_HDR_METASIZE);
 272             memcpy(&what->timestamp, x.value, STORE_HDR_METASIZE);
 273             break;
 274
 275         default:
 276             break;
 277         }
 278     }
 279
 280     StoreEntry *what;
 281     cache_key *index;
 282 };
 283
 284 bool
 285 storeRebuildLoadEntry(int fd, int diskIndex, MemBuf &buf,
 286                       struct _store_rebuild_data &counts)
 287 {
 288     if (fd < 0)
 289         return false;
 290
 291     assert(buf.hasSpace()); // caller must allocate
 292
 293     const int len = FD_READ_METHOD(fd, buf.space(), buf.spaceSize());
 294     statCounter.syscalls.disk.reads++;
 295     if (len < 0) {
 296         const int xerrno = errno;
 297         debugs(47, 1, "cache_dir[" << diskIndex << "]: " <<
 298             "failed to read swap entry meta data: " << xstrerr(xerrno));
 299         return false;
 300     }
 301
 302     buf.appended(len);
 303     return true;
 304 }
 305
 306 bool
 307 storeRebuildParseEntry(MemBuf &buf, StoreEntry &tmpe, cache_key *key,
 308                        struct _store_rebuild_data &counts,
 309                        uint64_t expectedSize)
 310 {
 311     int swap_hdr_len = 0;
 312     StoreMetaUnpacker aBuilder(buf.content(), buf.contentSize(), &swap_hdr_len);
 313     if (aBuilder.isBufferZero()) {
 314         debugs(47,5, HERE << "skipping empty record.");
 315         return false;
 316     }
 317
 318     if (!aBuilder.isBufferSane()) {
 319         debugs(47,1, "Warning: Ignoring malformed cache entry.");
 320         return false;
 321     }
 322
 323     StoreMeta *tlv_list = aBuilder.createStoreMeta();
 324     if (!tlv_list) {
 325         debugs(47, 1, HERE << "failed to get swap entry meta data list");
 326         return false;
 327     }
 328
 329     // TODO: consume parsed metadata?
 330
 331     debugs(47,7, HERE << "successful swap meta unpacking");
 332     memset(key, '\0', SQUID_MD5_DIGEST_LENGTH);
 333
 334     InitStoreEntry visitor(&tmpe, key);
 335     for_each(*tlv_list, visitor);
 336     storeSwapTLVFree(tlv_list);
 337     tlv_list = NULL;
 338
 339     if (storeKeyNull(key)) {
 340         debugs(47,1, HERE << "NULL swap entry key");
 341         return false;
 342     }
 343
 344     tmpe.key = key;
 345     /* check sizes */
 346
 347     if (expectedSize > 0) {
 348         if (tmpe.swap_file_sz == 0) {
 349             tmpe.swap_file_sz = expectedSize;
 350         } else if (tmpe.swap_file_sz == (uint64_t)(expectedSize - swap_hdr_len)) {
 351             tmpe.swap_file_sz = expectedSize;
 352         } else if (tmpe.swap_file_sz != expectedSize) {
 353             debugs(47, 1, HERE << "swap entry SIZE MISMATCH " <<
 354                    tmpe.swap_file_sz << "!=" << expectedSize);
 355             return false;
 356         }
 357     } else
 358     if (tmpe.swap_file_sz <= 0) {
 359         debugs(47, 1, HERE << "missing swap entry size: " << tmpe);
 360         return false;
 361     }
 362
 363     if (EBIT_TEST(tmpe.flags, KEY_PRIVATE)) {
 364         counts.badflags++;
 365         return false;
 366     }
 367
 368     return true;
 369 }
 370
 371 bool
 372 storeRebuildKeepEntry(const StoreEntry &tmpe, const cache_key *key,
 373                       struct _store_rebuild_data &counts)
 374 {
 375     /* this needs to become
 376      * 1) unpack url
 377      * 2) make synthetic request with headers ?? or otherwise search
 378      * for a matching object in the store
 379      * TODO FIXME change to new async api
 380      * TODO FIXME I think there is a race condition here with the
 381      * async api :
 382      * store A reads in object foo, searchs for it, and finds nothing.
 383      * store B reads in object foo, searchs for it, finds nothing.
 384      * store A gets called back with nothing, so registers the object
 385      * store B gets called back with nothing, so registers the object,
 386      * which will conflict when the in core index gets around to scanning
 387      * store B.
 388      *
 389      * this suggests that rather than searching for duplicates, the
 390      * index rebuild should just assume its the most recent accurate
 391      * store entry and whoever indexes the stores handles duplicates.
 392      */
 393     if (StoreEntry *e = Store::Root().get(key)) {
 394
 395         if (e->lastref >= tmpe.lastref) {
 396             /* key already exists, old entry is newer */
 397             /* keep old, ignore new */
 398             counts.dupcount++;
 399
 400             // For some stores, get() creates/unpacks a store entry. Signal
 401             // such stores that we will no longer use the get() result:
 402             e->lock();
 403             e->unlock();
 404
 405             return false;
 406         } else {
 407             /* URL already exists, this swapfile not being used */
 408             /* junk old, load new */
 409             e->release();       /* release old entry */
 410             counts.dupcount++;
 411         }
 412     }
 413
 414     return true;
 415 }