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