store_rebuild.cc
Go to the documentation of this file.
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 20 Store Rebuild Routines */
10 
11 #include "squid.h"
12 #include "DebugMessages.h"
13 #include "event.h"
14 #include "globals.h"
15 #include "md5.h"
16 #include "SquidConfig.h"
17 #include "SquidTime.h"
18 #include "StatCounters.h"
19 #include "Store.h"
20 #include "store/Disk.h"
21 #include "store_digest.h"
22 #include "store_key_md5.h"
23 #include "store_rebuild.h"
24 #include "StoreSearch.h"
25 // for tvSubDsec() which should be in SquidTime.h
26 #include "util.h"
27 
28 #include <cerrno>
29 
31 
32 static void storeCleanup(void *);
33 
34 // TODO: Either convert to Progress or replace with StoreRebuildData.
35 // TODO: Handle unknown totals (UFS cache_dir that lost swap.state) correctly.
36 typedef struct {
37  /* total number of "swap.state" entries that will be read */
38  int total;
39  /* number of entries read so far */
40  int scanned;
42 
44 
45 void
46 StoreRebuildData::updateStartTime(const timeval &dirStartTime)
47 {
48  startTime = started() ? std::min(startTime, dirStartTime) : dirStartTime;
49 }
50 
51 static void
52 storeCleanup(void *)
53 {
54  static int store_errors = 0;
55  static StoreSearchPointer currentSearch;
56  static int validated = 0;
57  static int seen = 0;
58 
59  if (currentSearch == NULL || currentSearch->isDone())
60  currentSearch = Store::Root().search();
61 
62  size_t statCount = 500;
63 
64  // TODO: Avoid the loop (and ENTRY_VALIDATED) unless opt_store_doublecheck.
65  while (statCount-- && !currentSearch->isDone() && currentSearch->next()) {
66  StoreEntry *e;
67 
68  e = currentSearch->currentItem();
69 
70  ++seen;
71 
73  continue;
74 
75  /*
76  * Calling StoreEntry->release() has no effect because we're
77  * still in 'store_rebuilding' state
78  */
79  if (!e->hasDisk())
80  continue;
81 
83  if (e->disk().doubleCheck(*e))
84  ++store_errors;
85 
87 
88  /*
89  * Only set the file bit if we know its a valid entry
90  * otherwise, set it in the validation procedure
91  */
92 
93  if ((++validated & 0x3FFFF) == 0)
94  /* TODO format the int with with a stream operator */
95  debugs(20, DBG_IMPORTANT, " " << validated << " Entries Validated so far.");
96  }
97 
98  if (currentSearch->isDone()) {
99  debugs(20, 2, "Seen: " << seen << " entries");
100  debugs(20, Important(43), "Completed Validation Procedure" <<
101  Debug::Extra << "Validated " << validated << " Entries" <<
102  Debug::Extra << "store_swap_size = " << (Store::Root().currentSize()/1024.0) << " KB");
105 
106  if (opt_store_doublecheck && store_errors) {
107  fatalf("Quitting after finding %d cache index inconsistencies. " \
108  "Removing cache index will force its slow rebuild. " \
109  "Removing -S will let Squid start with an inconsistent " \
110  "cache index (at your own risk).\n", store_errors);
111  }
112 
113  if (store_digest)
115 
116  currentSearch = NULL;
117  } else
118  eventAdd("storeCleanup", storeCleanup, NULL, 0.0, 1);
119 }
120 
121 /* meta data recreated from disk image in swap directory */
122 void
123 
125 {
126  if (dc) {
127  counts.objcount += dc->objcount;
128  counts.expcount += dc->expcount;
129  counts.scancount += dc->scancount;
130  counts.clashcount += dc->clashcount;
131  counts.dupcount += dc->dupcount;
132  counts.cancelcount += dc->cancelcount;
133  counts.invalid += dc->invalid;
134  counts.badflags += dc->badflags;
135  counts.bad_log_op += dc->bad_log_op;
136  counts.zero_object_sz += dc->zero_object_sz;
137  counts.validations += dc->validations;
138  counts.updateStartTime(dc->startTime);
139  }
140  // else the caller was not responsible for indexing its cache_dir
141 
144 
145  /*
146  * When store_dirs_rebuilding == 1, it means we are done reading
147  * or scanning all cache_dirs. Now report the stats and start
148  * the validation (storeCleanup()) thread.
149  */
150 
152  return;
153 
154  const auto dt = tvSubDsec(counts.startTime, current_time);
155 
156  debugs(20, Important(46), "Finished rebuilding storage from disk." <<
157  Debug::Extra << std::setw(7) << counts.scancount << " Entries scanned" <<
158  Debug::Extra << std::setw(7) << counts.invalid << " Invalid entries" <<
159  Debug::Extra << std::setw(7) << counts.badflags << " With invalid flags" <<
160  Debug::Extra << std::setw(7) << counts.objcount << " Objects loaded" <<
161  Debug::Extra << std::setw(7) << counts.expcount << " Objects expired" <<
162  Debug::Extra << std::setw(7) << counts.cancelcount << " Objects canceled" <<
163  Debug::Extra << std::setw(7) << counts.dupcount << " Duplicate URLs purged" <<
164  Debug::Extra << std::setw(7) << counts.clashcount << " Swapfile clashes avoided" <<
165  Debug::Extra << "Took " << std::setprecision(2) << dt << " seconds (" <<
166  ((double) counts.objcount / (dt > 0.0 ? dt : 1.0)) << " objects/sec).");
167  debugs(20, Important(56), "Beginning Validation Procedure");
168 
169  eventAdd("storeCleanup", storeCleanup, NULL, 0.0, 1);
170 
172 
174 }
175 
176 /*
177  * this is ugly. We don't actually start any rebuild threads here,
178  * but only initialize counters, etc. The rebuild threads are
179  * actually started by the filesystem "fooDirInit" function.
180  */
181 void
183 {
184  counts = StoreRebuildData(); // reset counters
185  /*
186  * Note: store_dirs_rebuilding is initialized to 1.
187  *
188  * When we parse the configuration and construct each swap dir,
189  * the construction of that raises the rebuild count.
190  *
191  * This prevents us from trying to write clean logs until we
192  * finished rebuilding - including after a reconfiguration that opens an
193  * existing swapdir. The corresponding decrement * occurs in
194  * storeCleanup(), when it is finished.
195  */
197  sizeof(store_rebuild_progress));
198 }
199 
200 /*
201  * A fs-specific rebuild procedure periodically reports its
202  * progress.
203  */
204 void
205 storeRebuildProgress(int sd_index, int total, int sofar)
206 {
207  static time_t last_report = 0;
208  // TODO: Switch to int64_t and fix handling of unknown totals.
209  double n = 0.0;
210  double d = 0.0;
211 
212  if (sd_index < 0)
213  return;
214 
215  if (sd_index >= Config.cacheSwap.n_configured)
216  return;
217 
218  if (NULL == RebuildProgress)
219  return;
220 
221  RebuildProgress[sd_index].total = total;
222 
223  RebuildProgress[sd_index].scanned = sofar;
224 
225  if (squid_curtime - last_report < 15)
226  return;
227 
228  for (sd_index = 0; sd_index < Config.cacheSwap.n_configured; ++sd_index) {
229  n += (double) RebuildProgress[sd_index].scanned;
230  d += (double) RebuildProgress[sd_index].total;
231  }
232 
233  debugs(20, Important(57), "Indexing cache entries: " << Progress(n, d));
234  last_report = squid_curtime;
235 }
236 
237 void
238 Progress::print(std::ostream &os) const
239 {
240  if (goal > 0) {
241  const auto savedPrecision = os.precision(2);
242  const auto percent = 100.0 * completed / goal;
243  os << percent << "% (" << completed << " out of " << goal << ")";
244  (void)os.precision(savedPrecision);
245  } else if (!completed && !goal) {
246  os << "nothing to do";
247  } else {
248  // unknown (i.e. negative) or buggy (i.e. zero when completed != 0) goal
249  os << completed;
250  }
251 }
252 
253 #include "fde.h"
254 #include "Generic.h"
255 #include "StoreMeta.h"
256 #include "StoreMetaUnpacker.h"
257 
258 struct InitStoreEntry : public unary_function<StoreMeta, void> {
259  InitStoreEntry(StoreEntry *anEntry, cache_key *aKey):what(anEntry),index(aKey) {}
260 
261  void operator()(StoreMeta const &x) {
262  switch (x.getType()) {
263 
264  case STORE_META_KEY:
266  memcpy(index, x.value, SQUID_MD5_DIGEST_LENGTH);
267  break;
268 
269  case STORE_META_STD:
270  struct old_metahdr {
271  time_t timestamp;
272  time_t lastref;
273  time_t expires;
274  time_t lastmod;
275  size_t swap_file_sz;
276  uint16_t refcount;
277  uint16_t flags;
278  } *tmp;
279  tmp = (struct old_metahdr *)x.value;
281  what->timestamp = tmp->timestamp;
282  what->lastref = tmp->lastref;
283  what->expires = tmp->expires;
284  what->lastModified(tmp->lastmod);
285  what->swap_file_sz = tmp->swap_file_sz;
286  what->refcount = tmp->refcount;
287  what->flags = tmp->flags;
288  break;
289 
290  case STORE_META_STD_LFS:
292  memcpy(&what->timestamp, x.value, STORE_HDR_METASIZE);
293  break;
294 
295  default:
296  break;
297  }
298  }
299 
302 };
303 
304 bool
305 storeRebuildLoadEntry(int fd, int diskIndex, MemBuf &buf, StoreRebuildData &)
306 {
307  if (fd < 0)
308  return false;
309 
310  assert(buf.hasSpace()); // caller must allocate
311 
312  const int len = FD_READ_METHOD(fd, buf.space(), buf.spaceSize());
313  ++ statCounter.syscalls.disk.reads;
314  if (len < 0) {
315  const int xerrno = errno;
316  debugs(47, DBG_IMPORTANT, "WARNING: cache_dir[" << diskIndex << "]: " <<
317  "Ignoring cached entry after meta data read failure: " << xstrerr(xerrno));
318  return false;
319  }
320 
321  buf.appended(len);
322  return true;
323 }
324 
325 bool
328  uint64_t expectedSize)
329 {
330  int swap_hdr_len = 0;
331  StoreMetaUnpacker aBuilder(buf.content(), buf.contentSize(), &swap_hdr_len);
332  if (aBuilder.isBufferZero()) {
333  debugs(47,5, HERE << "skipping empty record.");
334  return false;
335  }
336 
337  StoreMeta *tlv_list = nullptr;
338  try {
339  tlv_list = aBuilder.createStoreMeta();
340  } catch (const std::exception &e) {
341  debugs(47, DBG_IMPORTANT, "WARNING: Ignoring store entry because " << e.what());
342  return false;
343  }
344  assert(tlv_list);
345 
346  // TODO: consume parsed metadata?
347 
348  debugs(47,7, "successful swap meta unpacking; swap_file_sz=" << tmpe.swap_file_sz);
349  memset(key, '\0', SQUID_MD5_DIGEST_LENGTH);
350 
351  InitStoreEntry visitor(&tmpe, key);
352  for_each(*tlv_list, visitor);
353  storeSwapTLVFree(tlv_list);
354  tlv_list = NULL;
355 
356  if (storeKeyNull(key)) {
357  debugs(47, DBG_IMPORTANT, "WARNING: Ignoring keyless cache entry");
358  return false;
359  }
360 
361  tmpe.key = key;
362  /* check sizes */
363 
364  if (expectedSize > 0) {
365  if (tmpe.swap_file_sz == 0) {
366  tmpe.swap_file_sz = expectedSize;
367  } else if (tmpe.swap_file_sz == (uint64_t)(expectedSize - swap_hdr_len)) {
368  tmpe.swap_file_sz = expectedSize;
369  } else if (tmpe.swap_file_sz != expectedSize) {
370  debugs(47, DBG_IMPORTANT, "WARNING: Ignoring cache entry due to a " <<
371  "SIZE MISMATCH " << tmpe.swap_file_sz << "!=" << expectedSize);
372  return false;
373  }
374  } else if (tmpe.swap_file_sz <= 0) {
375  // if caller cannot handle unknown sizes, it must check after the call.
376  debugs(47, 7, "unknown size: " << tmpe);
377  }
378 
379  if (EBIT_TEST(tmpe.flags, KEY_PRIVATE)) {
380  ++ stats.badflags;
381  return false;
382  }
383 
384  return true;
385 }
386 
const char * xstrerr(int error)
Definition: xstrerror.cc:83
void storeRebuildProgress(int sd_index, int total, int sofar)
virtual bool doubleCheck(StoreEntry &)
Definition: Disk.cc:46
class Ping::pingStats_ stats
void * xcalloc(size_t n, size_t sz)
Definition: xalloc.cc:71
int64_t completed
the number of finished work steps
Definition: store_rebuild.h:55
time_t timestamp
Definition: Store.h:225
int64_t goal
the known total number of work steps (or negative)
Definition: store_rebuild.h:56
static std::ostream & Extra(std::ostream &os)
prefixes each grouped debugs() line after the first one in the group
Definition: Debug.h:99
unsigned char cache_key
Store key.
Definition: forward.h:29
#define EBIT_SET(flag, bit)
Definition: defines.h:67
int opt_store_doublecheck
bool storeRebuildParseEntry(MemBuf &buf, StoreEntry &tmpe, cache_key *key, StoreRebuildData &stats, uint64_t expectedSize)
parses entry buffer and validates entry metadata; fills e on success
SQUIDCEXTERN double tvSubDsec(struct timeval, struct timeval)
Definition: util.c:46
@ STORE_META_STD_LFS
Definition: StoreMeta.h:102
@ KEY_PRIVATE
Definition: enums.h:102
InitStoreEntry(StoreEntry *anEntry, cache_key *aKey)
struct StatCounters::@136::@140 disk
void updateStartTime(const timeval &dirStartTime)
maintain earliest initiation time across multiple indexing cache_dirs
cache_dir(s) indexing statistics
Definition: store_rebuild.h:20
uint16_t flags
Definition: Store.h:233
time_t expires
Definition: Store.h:227
Store::DiskConfig cacheSwap
Definition: SquidConfig.h:430
#define DBG_IMPORTANT
Definition: Debug.h:41
void storeRebuildComplete(StoreRebuildData *dc)
@ STORE_META_STD
Definition: StoreMeta.h:83
#define STORE_HDR_METASIZE_OLD
Definition: defines.h:115
struct StatCounters::@136 syscalls
#define SQUID_MD5_DIGEST_LENGTH
Definition: md5.h:66
mb_size_t contentSize() const
available data size
Definition: MemBuf.h:47
#define NULL
Definition: types.h:166
static void storeCleanup(void *)
#define debugs(SECTION, LEVEL, CONTENT)
Definition: Debug.h:123
@ ENTRY_VALIDATED
Definition: enums.h:113
uint16_t refcount
Definition: Store.h:232
bool hasDisk(const sdirno dirn=-1, const sfileno filen=-1) const
Definition: store.cc:1930
Definition: MemBuf.h:24
#define EBIT_TEST(flag, bit)
Definition: defines.h:69
std::ostream & HERE(std::ostream &s)
Definition: Debug.h:152
#define STORE_HDR_METASIZE
Definition: defines.h:114
timeval startTime
absolute time when the rebuild was initiated
Definition: store_rebuild.h:42
StoreMeta * createStoreMeta()
#define assert(EX)
Definition: assert.h:19
bool storeRebuildLoadEntry(int fd, int diskIndex, MemBuf &buf, StoreRebuildData &)
loads entry from disk; fills supplied memory buffer on success
void storeDigestNoteStoreReady(void)
virtual void next(void(callback)(void *cbdata), void *cbdata)=0
void fatalf(const char *fmt,...)
Definition: fatal.cc:68
int length
Definition: StoreMeta.h:133
void EVH void double
Definition: stub_event.cc:16
char * space()
returns buffer after data; does not check space existence
Definition: MemBuf.h:57
virtual bool isDone() const =0
virtual StoreEntry * currentItem()=0
StoreSearch * search()
Definition: Controller.cc:211
static store_rebuild_progress * RebuildProgress
static int store_dirs_rebuilding
the number of cache_dirs being rebuilt; TODO: move to Disks::Rebuilding
Definition: Controller.h:139
time_t squid_curtime
Definition: stub_time.cc:17
#define xfree
int FD_READ_METHOD(int fd, char *buf, int len)
Definition: fde.h:194
void appended(mb_size_t sz)
updates content size after external append
Definition: MemBuf.cc:228
void print(std::ostream &os) const
brief progress report suitable for level-0/1 debugging
#define Important(id)
Definition: DebugMessages.h:91
advancement of work that consists of (usually known number) of similar steps
Definition: store_rebuild.h:47
void * value
Definition: StoreMeta.h:134
int storeKeyNull(const cache_key *key)
virtual char getType() const =0
struct timeval current_time
Definition: stub_time.cc:15
bool started() const
whether we have worked on indexing this(these) cache_dir(s) before
Definition: store_rebuild.h:26
int64_t validations
the number of validated cache entries, slots
Definition: store_rebuild.h:41
void storeSwapTLVFree(tlv *n)
StoreEntry * what
char * content()
start of the added data
Definition: MemBuf.h:41
static StoreRebuildData counts
mb_size_t spaceSize() const
Definition: MemBuf.cc:157
bool isBufferZero()
useful for meta stored in pre-initialized (with zeros) db files
void storeRebuildStart(void)
uint64_t swap_file_sz
Definition: Store.h:231
bool hasSpace() const
Definition: MemBuf.h:72
CacheDigest * store_digest
Store::Disk & disk() const
the disk this entry is [being] cached on; asserts for entries w/o a disk
Definition: store.cc:1921
cache_key * index
void lastModified(const time_t when)
Definition: Store.h:177
void operator()(StoreMeta const &x)
#define STORE_META_KEY
Definition: defines.h:112
T & for_each(L const &head, T &visitor)
Definition: Generic.h:23
A const & min(A const &lhs, A const &rhs)
time_t lastref
Definition: Store.h:226
void eventAdd(const char *name, EVH *func, void *arg, double when, int weight, bool cbdata)
Definition: event.cc:108
class SquidConfig Config
Definition: SquidConfig.cc:12
StatCounters statCounter
Definition: StatCounters.cc:12
Controller & Root()
safely access controller singleton
Definition: Controller.cc:934

 

Introduction

Documentation

Support

Miscellaneous

Web Site Translations

Mirrors