RebuildState.cc
Go to the documentation of this file.
1 /*
2  * Copyright (C) 1996-2017 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 47 Store Directory Routines */
10 
11 #include "squid.h"
12 #include "fs_io.h"
13 #include "globals.h"
14 #include "RebuildState.h"
15 #include "SquidConfig.h"
16 #include "SquidTime.h"
17 #include "store/Disks.h"
18 #include "store_key_md5.h"
19 #include "store_rebuild.h"
20 #include "StoreSwapLogData.h"
21 #include "tools.h"
22 #include "UFSSwapLogParser.h"
23 
24 #include <cerrno>
25 #include <cmath>
26 #if HAVE_SYS_STAT_H
27 #include <sys/stat.h>
28 #endif
29 
30 CBDATA_NAMESPACED_CLASS_INIT(Fs::Ufs,RebuildState);
31 
33  sd(aSwapDir),
34  n_read(0),
35  LogParser(NULL),
36  curlvl1(0),
37  curlvl2(0),
38  in_dir(0),
39  done(0),
40  fn(0),
41  entry(NULL),
42  td(NULL),
43  e(NULL),
44  fromLog(true),
45  _done(false),
46  cbdata(NULL)
47 {
48  *fullpath = 0;
49  *fullfilename = 0;
50 
51  /*
52  * If the swap.state file exists in the cache_dir, then
53  * we'll use commonUfsDirRebuildFromSwapLog(), otherwise we'll
54  * use commonUfsDirRebuildFromDirectory() to open up each file
55  * and suck in the meta data.
56  */
57  int clean = 0; //TODO: change to bool
58  int zeroLengthLog = 0;
59  FILE *fp = sd->openTmpSwapLog(&clean, &zeroLengthLog);
60 
61  if (fp && !zeroLengthLog)
63 
64  if (LogParser == NULL ) {
65  fromLog = false;
66 
67  if (fp != NULL)
68  fclose(fp);
69 
70  } else {
71  fromLog = true;
72  flags.clean = (clean != 0);
73  }
74 
75  if (!clean)
76  flags.need_to_validate = true;
77 
78  debugs(47, DBG_IMPORTANT, "Rebuilding storage in " << sd->path << " (" <<
79  (clean ? "clean log" : (LogParser ? "dirty log" : "no log")) << ")");
80 }
81 
83 {
84  sd->closeTmpSwapLog();
85 
86  if (LogParser)
87  delete LogParser;
88 }
89 
90 void
92 {
93  RebuildState *rb = (RebuildState *)data;
94  if (!reconfiguring)
95  rb->rebuildStep();
96 
97  // delay storeRebuildComplete() when reconfiguring to protect storeCleanup()
98  if (!rb->isDone() || reconfiguring)
99  eventAdd("storeRebuild", RebuildStep, rb, 0.01, 1);
100  else {
103  delete rb;
104  }
105 }
106 
108 void
110 {
111  currentEntry(NULL);
112 
113  // Balance our desire to maximize the number of entries processed at once
114  // (and, hence, minimize overheads and total rebuild time) with a
115  // requirement to also process Coordinator events, disk I/Os, etc.
116  const int maxSpentMsec = 50; // keep small: most RAM I/Os are under 1ms
117  const timeval loopStart = current_time;
118 
119  const int totalEntries = LogParser ? LogParser->SwapLogEntries() : -1;
120 
121  while (!isDone()) {
122  if (fromLog)
123  rebuildFromSwapLog();
124  else
125  rebuildFromDirectory();
126 
127  // TODO: teach storeRebuildProgress to handle totalEntries <= 0
128  if (totalEntries > 0 && (n_read % 4000 == 0))
129  storeRebuildProgress(sd->index, totalEntries, n_read);
130 
132  continue; // skip "few entries at a time" check below
133 
134  getCurrentTime();
135  const double elapsedMsec = tvSubMsec(loopStart, current_time);
136  if (elapsedMsec > maxSpentMsec || elapsedMsec < 0) {
137  debugs(47, 5, HERE << "pausing after " << n_read << " entries in " <<
138  elapsedMsec << "ms; " << (elapsedMsec/n_read) << "ms per entry");
139  break;
140  }
141  }
142 }
143 
145 void
147 {
149 
150  struct stat sb;
151  int fd = -1;
152  debugs(47, 3, HERE << "DIR #" << sd->index);
153 
154  assert(fd == -1);
155  sfileno filn = 0;
156  int size;
157  fd = getNextFile(&filn, &size);
158 
159  if (fd == -2) {
160  debugs(47, DBG_IMPORTANT, "Done scanning " << sd->path << " dir (" <<
161  n_read << " entries)");
162  _done = true;
163  return;
164  } else if (fd < 0) {
165  return;
166  }
167 
168  assert(fd > -1);
169  /* lets get file stats here */
170 
171  ++n_read;
172 
173  if (fstat(fd, &sb) < 0) {
174  int xerrno = errno;
175  debugs(47, DBG_IMPORTANT, MYNAME << "fstat(FD " << fd << "): " << xstrerr(xerrno));
176  file_close(fd);
178  fd = -1;
179  return;
180  }
181 
182  MemBuf buf;
184  if (!storeRebuildLoadEntry(fd, sd->index, buf, counts))
185  return;
186 
187  const uint64_t expectedSize = sb.st_size > 0 ?
188  static_cast<uint64_t>(sb.st_size) : 0;
189 
190  StoreEntry tmpe;
191  const bool parsed = storeRebuildParseEntry(buf, tmpe, key, counts,
192  expectedSize);
193 
194  file_close(fd);
196  fd = -1;
197 
198  bool accepted = parsed && tmpe.swap_file_sz > 0;
199  if (parsed && !accepted) {
200  debugs(47, DBG_IMPORTANT, "WARNING: Ignoring ufs cache entry with " <<
201  "unknown size: " << tmpe);
202  accepted = false;
203  }
204 
205  if (!accepted) {
206  // XXX: shouldn't this be a call to commonUfsUnlink?
207  sd->unlinkFile(filn); // should we unlink in all failure cases?
208  return;
209  }
210 
211  if (!storeRebuildKeepEntry(tmpe, key, counts))
212  return;
213 
214  ++counts.objcount;
215  // tmpe.dump(5);
216  currentEntry(sd->addDiskRestore(key,
217  filn,
218  tmpe.swap_file_sz,
219  tmpe.expires,
220  tmpe.timestamp,
221  tmpe.lastref,
222  tmpe.lastModified(),
223  tmpe.refcount, /* refcount */
224  tmpe.flags, /* flags */
225  (int) flags.clean));
226  storeDirSwapLog(currentEntry(), SWAP_LOG_ADD);
227 }
228 
229 StoreEntry *
231 {
232  return e;
233 }
234 
235 void
237 {
238  e = newValue;
239 }
240 
242 void
244 {
245  StoreSwapLogData swapData;
246 
247  if (LogParser->ReadRecord(swapData) != 1) {
248  debugs(47, DBG_IMPORTANT, "Done reading " << sd->path << " swaplog (" << n_read << " entries)");
249  LogParser->Close();
250  delete LogParser;
251  LogParser = NULL;
252  _done = true;
253  return;
254  }
255 
256  ++n_read;
257 
258  if (!swapData.sane()) {
259  ++counts.invalid;
260  return;
261  }
262 
263  /*
264  * BC: during 2.4 development, we changed the way swap file
265  * numbers are assigned and stored. The high 16 bits used
266  * to encode the SD index number. There used to be a call
267  * to storeDirProperFileno here that re-assigned the index
268  * bits. Now, for backwards compatibility, we just need
269  * to mask it off.
270  */
271  swapData.swap_filen &= 0x00FFFFFF;
272 
273  debugs(47, 3, HERE << swap_log_op_str[(int) swapData.op] << " " <<
274  storeKeyText(swapData.key) << " "<< std::setfill('0') <<
275  std::hex << std::uppercase << std::setw(8) <<
276  swapData.swap_filen);
277 
278  if (swapData.op == SWAP_LOG_ADD) {
279  (void) 0;
280  } else if (swapData.op == SWAP_LOG_DEL) {
281  /* Delete unless we already have a newer copy anywhere in any store */
282  /* this needs to become
283  * 1) unpack url
284  * 2) make synthetic request with headers ?? or otherwise search
285  * for a matching object in the store
286  * TODO FIXME change to new async api
287  */
288  currentEntry (Store::Root().get(swapData.key));
289 
290  if (currentEntry() != NULL && swapData.lastref >= e->lastref) {
291  undoAdd();
292  --counts.objcount;
294  }
295  return;
296  } else {
297  const double
298  x = ::log(static_cast<double>(++counts.bad_log_op)) / ::log(10.0);
299 
300  if (0.0 == x - (double) (int) x)
301  debugs(47, DBG_IMPORTANT, "WARNING: " << counts.bad_log_op << " invalid swap log entries found");
302 
303  ++counts.invalid;
304 
305  return;
306  }
307 
308  ++counts.scancount; // XXX: should not this be incremented earlier?
309 
310  if (!sd->validFileno(swapData.swap_filen, 0)) {
311  ++counts.invalid;
312  return;
313  }
314 
315  if (EBIT_TEST(swapData.flags, KEY_PRIVATE)) {
316  ++counts.badflags;
317  return;
318  }
319 
320  /* this needs to become
321  * 1) unpack url
322  * 2) make synthetic request with headers ?? or otherwise search
323  * for a matching object in the store
324  * TODO FIXME change to new async api
325  */
326  currentEntry (Store::Root().get(swapData.key));
327 
328  int used; /* is swapfile already in use? */
329 
330  used = sd->mapBitTest(swapData.swap_filen);
331 
332  /* If this URL already exists in the cache, does the swap log
333  * appear to have a newer entry? Compare 'lastref' from the
334  * swap log to e->lastref. */
335  /* is the log entry newer than current entry? */
336  int disk_entry_newer = currentEntry() ? (swapData.lastref > currentEntry()->lastref ? 1 : 0) : 0;
337 
338  if (used && !disk_entry_newer) {
339  /* log entry is old, ignore it */
340  ++counts.clashcount;
341  return;
342  } else if (used && currentEntry() && currentEntry()->swap_filen == swapData.swap_filen && currentEntry()->swap_dirn == sd->index) {
343  /* swapfile taken, same URL, newer, update meta */
344 
345  if (currentEntry()->store_status == STORE_OK) {
346  currentEntry()->lastref = swapData.timestamp;
347  currentEntry()->timestamp = swapData.timestamp;
348  currentEntry()->expires = swapData.expires;
349  currentEntry()->lastModified(swapData.lastmod);
350  currentEntry()->flags = swapData.flags;
351  currentEntry()->refcount += swapData.refcount;
352  sd->dereference(*currentEntry());
353  } else {
354  debug_trap("commonUfsDirRebuildFromSwapLog: bad condition");
355  debugs(47, DBG_IMPORTANT, HERE << "bad condition");
356  }
357  return;
358  } else if (used) {
359  /* swapfile in use, not by this URL, log entry is newer */
360  /* This is sorta bad: the log entry should NOT be newer at this
361  * point. If the log is dirty, the filesize check should have
362  * caught this. If the log is clean, there should never be a
363  * newer entry. */
364  debugs(47, DBG_IMPORTANT, "WARNING: newer swaplog entry for dirno " <<
365  sd->index << ", fileno "<< std::setfill('0') << std::hex <<
366  std::uppercase << std::setw(8) << swapData.swap_filen);
367 
368  /* I'm tempted to remove the swapfile here just to be safe,
369  * but there is a bad race condition in the NOVM version if
370  * the swapfile has recently been opened for writing, but
371  * not yet opened for reading. Because we can't map
372  * swapfiles back to StoreEntrys, we don't know the state
373  * of the entry using that file. */
374  /* We'll assume the existing entry is valid, probably because
375  * were in a slow rebuild and the the swap file number got taken
376  * and the validation procedure hasn't run. */
377  assert(flags.need_to_validate);
378  ++counts.clashcount;
379  return;
380  } else if (currentEntry() && !disk_entry_newer) {
381  /* key already exists, current entry is newer */
382  /* keep old, ignore new */
383  ++counts.dupcount;
384  return;
385  } else if (currentEntry()) {
386  /* key already exists, this swapfile not being used */
387  /* junk old, load new */
388  undoAdd();
389  --counts.objcount;
390  ++counts.dupcount;
391  } else {
392  /* URL doesnt exist, swapfile not in use */
393  /* load new */
394  (void) 0;
395  }
396 
397  ++counts.objcount;
398 
399  currentEntry(sd->addDiskRestore(swapData.key,
400  swapData.swap_filen,
401  swapData.swap_file_sz,
402  swapData.expires,
403  swapData.timestamp,
404  swapData.lastref,
405  swapData.lastmod,
406  swapData.refcount,
407  swapData.flags,
408  (int) flags.clean));
409 
410  storeDirSwapLog(currentEntry(), SWAP_LOG_ADD);
411 }
412 
414 void
416 {
417  StoreEntry *added = currentEntry();
418  assert(added);
419  currentEntry(NULL);
420 
421  // TODO: Why bother with these two if we are going to release?!
422  added->expireNow();
423  added->releaseRequest();
424 
425  if (added->swap_filen > -1) {
426  SwapDir *someDir = INDEXSD(added->swap_dirn);
427  assert(someDir);
428  if (UFSSwapDir *ufsDir = dynamic_cast<UFSSwapDir*>(someDir))
429  ufsDir->undoAddDiskRestore(added);
430  // else the entry was loaded from and/or is currently in a non-UFS dir
431  // Thus, there is no use in preserving its disk file (the only purpose
432  // of undoAddDiskRestore!), even if we could. Instead, we release the
433  // the entry and [eventually] unlink its disk file or free its slot.
434  }
435 
436  added->release();
437 }
438 
439 int
441 {
442  int fd = -1;
443  int dirs_opened = 0;
444  debugs(47, 3, HERE << "flag=" << flags.init << ", " <<
445  sd->index << ": /"<< std::setfill('0') << std::hex <<
446  std::uppercase << std::setw(2) << curlvl1 << "/" << std::setw(2) <<
447  curlvl2);
448 
449  if (done)
450  return -2;
451 
452  while (fd < 0 && done == 0) {
453  fd = -1;
454 
455  if (!flags.init) { /* initialize, open first file */
456  // XXX: 0's should not be needed, constructor inits now
457  done = 0;
458  curlvl1 = 0;
459  curlvl2 = 0;
460  in_dir = 0;
461  flags.init = true;
463  }
464 
465  if (0 == in_dir) { /* we need to read in a new directory */
466  snprintf(fullpath, sizeof(fullpath), "%s/%02X/%02X",
467  sd->path,
468  curlvl1, curlvl2);
469 
470  if (dirs_opened)
471  return -1;
472 
473  td = opendir(fullpath);
474 
475  ++dirs_opened;
476 
477  if (!td) {
478  int xerrno = errno;
479  debugs(47, DBG_IMPORTANT, MYNAME << "error in opendir (" << fullpath << "): " << xstrerr(xerrno));
480  } else {
481  entry = readdir(td); /* skip . and .. */
482  entry = readdir(td);
483 
484  if (entry == NULL && errno == ENOENT)
485  debugs(47, DBG_IMPORTANT, HERE << "WARNING: directory does not exist!");
486  debugs(47, 3, HERE << "Directory " << fullpath);
487  }
488  }
489 
490  if (td != NULL && (entry = readdir(td)) != NULL) {
491  ++in_dir;
492 
493  if (sscanf(entry->d_name, "%x", &fn) != 1) {
494  debugs(47, 3, HERE << "invalid entry " << entry->d_name);
495  continue;
496  }
497 
498  if (!UFSSwapDir::FilenoBelongsHere(fn, sd->index, curlvl1, curlvl2)) {
499  debugs(47, 3, HERE << std::setfill('0') <<
500  std::hex << std::uppercase << std::setw(8) << fn <<
501  " does not belong in " << std::dec << sd->index << "/" <<
502  curlvl1 << "/" << curlvl2);
503 
504  continue;
505  }
506 
507  if (sd->mapBitTest(fn)) {
508  debugs(47, 3, HERE << "Locked, continuing with next.");
509  continue;
510  }
511 
512  snprintf(fullfilename, sizeof(fullfilename), "%s/%s",
513  fullpath, entry->d_name);
514  debugs(47, 3, HERE << "Opening " << fullfilename);
515  fd = file_open(fullfilename, O_RDONLY | O_BINARY);
516 
517  if (fd < 0) {
518  int xerrno = errno;
519  debugs(47, DBG_IMPORTANT, MYNAME << "error opening " << fullfilename << ": " << xstrerr(xerrno));
520  } else
522 
523  continue;
524  }
525 
526  if (td != NULL)
527  closedir(td);
528 
529  td = NULL;
530 
531  in_dir = 0;
532 
533  if (sd->validL2(++curlvl2))
534  continue;
535 
536  curlvl2 = 0;
537 
538  if (sd->validL1(++curlvl1))
539  continue;
540 
541  curlvl1 = 0;
542 
543  done = 1;
544  }
545 
546  *filn_p = fn;
547  return fd;
548 }
549 
550 bool
552 {
553  return false;
554 }
555 
556 bool
558 {
559  return _done;
560 }
561 
562 StoreEntry *
564 {
565  return currentEntry();
566 }
567 
sdirno swap_dirn
Definition: Store.h:179
void rebuildStep()
load entries from swap.state or files until we run out of entries or time
static int store_dirs_rebuilding
the number of cache_dirs being rebuilt; TODO: move to Disks::Rebuilding
Definition: Controller.h:90
RebuildState(RefCount< UFSSwapDir > sd)
Definition: RebuildState.cc:32
#define assert(EX)
Definition: assert.h:17
CBDATA_NAMESPACED_CLASS_INIT(Fs::Ufs, RebuildState)
void storeRebuildComplete(StoreRebuildData *dc)
virtual void release(const bool shareable=false)
Definition: store.cc:1250
virtual bool isDone() const
Definition: cbdata.cc:60
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
void storeDirSwapLog(const StoreEntry *e, int op)
Definition: Disks.cc:712
bool sane() const
consistency self-check: whether the data appears to make sense
unsigned char cache_key
Store key.
Definition: forward.h:29
char * fn
Definition: membanger.c:36
void log(char *format,...)
void lastModified(const time_t when)
Definition: Store.h:142
void expireNow()
Definition: store.cc:815
const char * storeKeyText(const cache_key *key)
int file_open(const char *path, int mode)
Definition: fs_io.cc:46
sfileno swap_filen
unique ID inside a cache_dir for swapped out entries; -1 for others
Definition: Store.h:177
Controller & Root()
safely access controller singleton
Definition: Controller.cc:619
virtual StoreEntry * currentItem()
time_t expires
Definition: Store.h:167
struct timeval current_time
Definition: stub_time.cc:15
int opt_foreground_rebuild
time_t timestamp
Definition: Store.h:165
void rebuildFromDirectory()
process one cache file
void init(mb_size_t szInit, mb_size_t szMax)
Definition: MemBuf.cc:105
static UFSSwapLogParser * GetUFSSwapLogParser(FILE *fp)
char fullfilename[MAXPATHLEN *2]
Definition: RebuildState.h:58
uint64_t swap_file_sz
Definition: Store.h:171
int tvSubMsec(struct timeval, struct timeval)
Definition: stub_time.cc:20
const char * xstrerr(int error)
Definition: xstrerror.cc:83
bool storeRebuildKeepEntry(const StoreEntry &tmpe, const cache_key *key, StoreRebuildData &stats)
checks whether the loaded entry should be kept; updates counters
#define debugs(SECTION, LEVEL, CONTENT)
Definition: Debug.h:123
unsigned char key[SQUID_MD5_DIGEST_LENGTH]
#define true
Definition: GnuRegex.c:234
#define DBG_IMPORTANT
Definition: Debug.h:45
static StoreRebuildData counts
#define SQUID_MD5_DIGEST_LENGTH
Definition: md5.h:66
FILE * fp
Definition: membanger.c:35
static EVH RebuildStep
Definition: RebuildState.h:29
SwappedTime timestamp
void releaseRequest(const bool shareable=false)
Definition: store.cc:474
StoreRebuildData counts
Definition: RebuildState.h:60
uint16_t flags
Definition: Store.h:173
int getNextFile(sfileno *, int *size)
signed_int32_t sfileno
Definition: forward.h:22
#define INDEXSD(i)
Definition: SquidConfig.h:64
#define SM_PAGE_SIZE
Definition: defines.h:102
void undoAdd()
undo the effects of adding an entry in rebuildFromSwapLog()
uint16_t refcount
Definition: Store.h:172
void const char * buf
Definition: stub_helper.cc:16
std::ostream & HERE(std::ostream &s)
Definition: Debug.h:147
virtual bool error() const
const char * swap_log_op_str[]
Definition: enums.h:46
bool SIGHDLR int STUB void int
Definition: stub_tools.cc:68
time_t getCurrentTime(void)
Get current time.
void eventAdd(const char *name, EVH *func, void *arg, double when, int weight, bool cbdata)
Definition: event.cc:109
#define MYNAME
Definition: Debug.h:160
static bool FilenoBelongsHere(int fn, int cachedir, int level1dir, int level2dir)
Definition: UFSSwapDir.cc:1155
RefCount< UFSSwapDir > sd
Definition: RebuildState.h:38
Store::DiskConfig cacheSwap
Definition: SquidConfig.h:418
int store_open_disk_fd
Fs::Ufs::UFSSwapLogParser * LogParser
Definition: RebuildState.h:41
Definition: MemBuf.h:23
void const cache_key * key
void storeRebuildProgress(int sd_index, int total, int sofar)
char fullpath[MAXPATHLEN]
Definition: RebuildState.h:57
time_t lastref
Definition: Store.h:166
#define O_BINARY
Definition: defines.h:204
void debug_trap(const char *message)
Definition: tools.cc:403
StoreEntry * currentEntry() const
void file_close(int fd)
Definition: fs_io.cc:76
bool storeRebuildLoadEntry(int fd, int diskIndex, MemBuf &buf, StoreRebuildData &)
loads entry from disk; fills supplied memory buffer on success
void rebuildFromSwapLog()
process one swap log entry
#define EBIT_TEST(flag, bit)
Definition: defines.h:107
class SquidConfig Config
Definition: SquidConfig.cc:12
#define NULL
Definition: types.h:166
int reconfiguring
int size
Definition: ModDevPoll.cc:77
#define false
Definition: GnuRegex.c:233
struct Fs::Ufs::RebuildState::Flags flags
manages a single cache_dir
Definition: Disk.h:21

 

Introduction

Documentation

Support

Miscellaneous

Web Site Translations

Mirrors