RebuildState.cc
Go to the documentation of this file.
1 /*
2  * Copyright (C) 1996-2018 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  fromLog(true),
44  _done(false),
45  cbdata(NULL)
46 {
47  *fullpath = 0;
48  *fullfilename = 0;
49 
50  /*
51  * If the swap.state file exists in the cache_dir, then
52  * we'll use commonUfsDirRebuildFromSwapLog(), otherwise we'll
53  * use commonUfsDirRebuildFromDirectory() to open up each file
54  * and suck in the meta data.
55  */
56  int clean = 0; //TODO: change to bool
57  int zeroLengthLog = 0;
58  FILE *fp = sd->openTmpSwapLog(&clean, &zeroLengthLog);
59 
60  if (fp && !zeroLengthLog)
62 
63  if (LogParser == NULL ) {
64  fromLog = false;
65 
66  if (fp != NULL)
67  fclose(fp);
68 
69  } else {
70  fromLog = true;
71  flags.clean = (clean != 0);
72  }
73 
74  if (!clean)
75  flags.need_to_validate = true;
76 
77  debugs(47, DBG_IMPORTANT, "Rebuilding storage in " << sd->path << " (" <<
78  (clean ? "clean log" : (LogParser ? "dirty log" : "no log")) << ")");
79 }
80 
82 {
83  sd->closeTmpSwapLog();
84 
85  if (LogParser)
86  delete LogParser;
87 }
88 
89 void
91 {
92  RebuildState *rb = (RebuildState *)data;
93  if (!reconfiguring)
94  rb->rebuildStep();
95 
96  // delay storeRebuildComplete() when reconfiguring to protect storeCleanup()
97  if (!rb->isDone() || reconfiguring)
98  eventAdd("storeRebuild", RebuildStep, rb, 0.01, 1);
99  else {
102  delete rb;
103  }
104 }
105 
107 void
109 {
110  // Balance our desire to maximize the number of entries processed at once
111  // (and, hence, minimize overheads and total rebuild time) with a
112  // requirement to also process Coordinator events, disk I/Os, etc.
113  const int maxSpentMsec = 50; // keep small: most RAM I/Os are under 1ms
114  const timeval loopStart = current_time;
115 
116  const int totalEntries = LogParser ? LogParser->SwapLogEntries() : -1;
117 
118  while (!isDone()) {
119  if (fromLog)
120  rebuildFromSwapLog();
121  else
122  rebuildFromDirectory();
123 
124  // TODO: teach storeRebuildProgress to handle totalEntries <= 0
125  if (totalEntries > 0 && (n_read % 4000 == 0))
126  storeRebuildProgress(sd->index, totalEntries, n_read);
127 
129  continue; // skip "few entries at a time" check below
130 
131  getCurrentTime();
132  const double elapsedMsec = tvSubMsec(loopStart, current_time);
133  if (elapsedMsec > maxSpentMsec || elapsedMsec < 0) {
134  debugs(47, 5, HERE << "pausing after " << n_read << " entries in " <<
135  elapsedMsec << "ms; " << (elapsedMsec/n_read) << "ms per entry");
136  break;
137  }
138  }
139 }
140 
142 void
144 {
146 
147  struct stat sb;
148  int fd = -1;
149  debugs(47, 3, HERE << "DIR #" << sd->index);
150 
151  assert(fd == -1);
152  sfileno filn = 0;
153  int size;
154  fd = getNextFile(&filn, &size);
155 
156  if (fd == -2) {
157  debugs(47, DBG_IMPORTANT, "Done scanning " << sd->path << " dir (" <<
158  n_read << " entries)");
159  _done = true;
160  return;
161  } else if (fd < 0) {
162  return;
163  }
164 
165  assert(fd > -1);
166  /* lets get file stats here */
167 
168  ++n_read;
169 
170  if (fstat(fd, &sb) < 0) {
171  int xerrno = errno;
172  debugs(47, DBG_IMPORTANT, MYNAME << "fstat(FD " << fd << "): " << xstrerr(xerrno));
173  file_close(fd);
175  fd = -1;
176  return;
177  }
178 
179  MemBuf buf;
181  if (!storeRebuildLoadEntry(fd, sd->index, buf, counts))
182  return;
183 
184  const uint64_t expectedSize = sb.st_size > 0 ?
185  static_cast<uint64_t>(sb.st_size) : 0;
186 
187  StoreEntry tmpe;
188  const bool parsed = storeRebuildParseEntry(buf, tmpe, key, counts,
189  expectedSize);
190 
191  file_close(fd);
193  fd = -1;
194 
195  bool accepted = parsed && tmpe.swap_file_sz > 0;
196  if (parsed && !accepted) {
197  debugs(47, DBG_IMPORTANT, "WARNING: Ignoring ufs cache entry with " <<
198  "unknown size: " << tmpe);
199  accepted = false;
200  }
201 
202  if (!accepted) {
203  // XXX: shouldn't this be a call to commonUfsUnlink?
204  sd->unlinkFile(filn); // should we unlink in all failure cases?
205  return;
206  }
207 
208  addIfFresh(key,
209  filn,
210  tmpe.swap_file_sz,
211  tmpe.expires,
212  tmpe.timestamp,
213  tmpe.lastref,
214  tmpe.lastModified(),
215  tmpe.refcount,
216  tmpe.flags);
217 }
218 
220 void
222  sfileno file_number,
223  uint64_t swap_file_sz,
224  time_t expires,
225  time_t timestamp,
226  time_t lastref,
227  time_t lastmod,
228  uint32_t refcount,
229  uint16_t newFlags)
230 {
231  if (!evictStaleAndContinue(key, lastref, counts.dupcount))
232  return;
233 
234  ++counts.objcount;
235  const auto addedEntry = sd->addDiskRestore(key,
236  file_number,
237  swap_file_sz,
238  expires,
239  timestamp,
240  lastref,
241  lastmod,
242  refcount,
243  newFlags,
244  0 /* XXX: unused */);
246 }
247 
251 bool
252 Fs::Ufs::RebuildState::evictStaleAndContinue(const cache_key *candidateKey, const time_t maxRef, int &staleCount)
253 {
254  if (auto *indexedEntry = Store::Root().peek(candidateKey)) {
255 
256  if (indexedEntry->lastref >= maxRef) {
257  indexedEntry->abandon("Fs::Ufs::RebuildState::evictStaleAndContinue");
258  ++counts.clashcount;
259  return false;
260  }
261 
262  ++staleCount;
263  indexedEntry->release(true); // evict previously indexedEntry
264  }
265 
266  return true;
267 }
268 
270 void
272 {
273  StoreSwapLogData swapData;
274 
275  if (LogParser->ReadRecord(swapData) != 1) {
276  debugs(47, DBG_IMPORTANT, "Done reading " << sd->path << " swaplog (" << n_read << " entries)");
277  LogParser->Close();
278  delete LogParser;
279  LogParser = NULL;
280  _done = true;
281  return;
282  }
283 
284  ++n_read;
285 
286  if (!swapData.sane()) {
287  ++counts.invalid;
288  return;
289  }
290 
291  /*
292  * BC: during 2.4 development, we changed the way swap file
293  * numbers are assigned and stored. The high 16 bits used
294  * to encode the SD index number. There used to be a call
295  * to storeDirProperFileno here that re-assigned the index
296  * bits. Now, for backwards compatibility, we just need
297  * to mask it off.
298  */
299  swapData.swap_filen &= 0x00FFFFFF;
300 
301  debugs(47, 3, HERE << swap_log_op_str[(int) swapData.op] << " " <<
302  storeKeyText(swapData.key) << " "<< std::setfill('0') <<
303  std::hex << std::uppercase << std::setw(8) <<
304  swapData.swap_filen);
305 
306  if (swapData.op == SWAP_LOG_ADD) {
307  (void) 0;
308  } else if (swapData.op == SWAP_LOG_DEL) {
309  // remove any older or same-age entry; +1 covers same-age entries
310  (void)evictStaleAndContinue(swapData.key, swapData.lastref+1, counts.cancelcount);
311  return;
312  } else {
313  const double
314  x = ::log(static_cast<double>(++counts.bad_log_op)) / ::log(10.0);
315 
316  if (0.0 == x - (double) (int) x)
317  debugs(47, DBG_IMPORTANT, "WARNING: " << counts.bad_log_op << " invalid swap log entries found");
318 
319  ++counts.invalid;
320 
321  return;
322  }
323 
324  ++counts.scancount; // XXX: should not this be incremented earlier?
325 
326  if (!sd->validFileno(swapData.swap_filen, 0)) {
327  ++counts.invalid;
328  return;
329  }
330 
331  if (EBIT_TEST(swapData.flags, KEY_PRIVATE)) {
332  ++counts.badflags;
333  return;
334  }
335 
336  if (sd->mapBitTest(swapData.swap_filen)) {
337  // While we were scanning the logs, some (unrelated) entry was added to
338  // our disk using our logged swap_filen. We could change our swap_filen
339  // and move the store file, but there is no Store API to do that (TODO).
340  ++counts.clashcount;
341  return;
342  }
343 
344  addIfFresh(swapData.key,
345  swapData.swap_filen,
346  swapData.swap_file_sz,
347  swapData.expires,
348  swapData.timestamp,
349  swapData.lastref,
350  swapData.lastmod,
351  swapData.refcount,
352  swapData.flags);
353 }
354 
355 int
357 {
358  int fd = -1;
359  int dirs_opened = 0;
360  debugs(47, 3, HERE << "flag=" << flags.init << ", " <<
361  sd->index << ": /"<< std::setfill('0') << std::hex <<
362  std::uppercase << std::setw(2) << curlvl1 << "/" << std::setw(2) <<
363  curlvl2);
364 
365  if (done)
366  return -2;
367 
368  while (fd < 0 && done == 0) {
369  fd = -1;
370 
371  if (!flags.init) { /* initialize, open first file */
372  // XXX: 0's should not be needed, constructor inits now
373  done = 0;
374  curlvl1 = 0;
375  curlvl2 = 0;
376  in_dir = 0;
377  flags.init = true;
379  }
380 
381  if (0 == in_dir) { /* we need to read in a new directory */
382  snprintf(fullpath, sizeof(fullpath), "%s/%02X/%02X",
383  sd->path,
384  curlvl1, curlvl2);
385 
386  if (dirs_opened)
387  return -1;
388 
389  td = opendir(fullpath);
390 
391  ++dirs_opened;
392 
393  if (!td) {
394  int xerrno = errno;
395  debugs(47, DBG_IMPORTANT, MYNAME << "error in opendir (" << fullpath << "): " << xstrerr(xerrno));
396  } else {
397  entry = readdir(td); /* skip . and .. */
398  entry = readdir(td);
399 
400  if (entry == NULL && errno == ENOENT)
401  debugs(47, DBG_IMPORTANT, HERE << "WARNING: directory does not exist!");
402  debugs(47, 3, HERE << "Directory " << fullpath);
403  }
404  }
405 
406  if (td != NULL && (entry = readdir(td)) != NULL) {
407  ++in_dir;
408 
409  if (sscanf(entry->d_name, "%x", &fn) != 1) {
410  debugs(47, 3, HERE << "invalid entry " << entry->d_name);
411  continue;
412  }
413 
414  if (!UFSSwapDir::FilenoBelongsHere(fn, sd->index, curlvl1, curlvl2)) {
415  debugs(47, 3, HERE << std::setfill('0') <<
416  std::hex << std::uppercase << std::setw(8) << fn <<
417  " does not belong in " << std::dec << sd->index << "/" <<
418  curlvl1 << "/" << curlvl2);
419 
420  continue;
421  }
422 
423  if (sd->mapBitTest(fn)) {
424  debugs(47, 3, HERE << "Locked, continuing with next.");
425  continue;
426  }
427 
428  snprintf(fullfilename, sizeof(fullfilename), "%s/%s",
429  fullpath, entry->d_name);
430  debugs(47, 3, HERE << "Opening " << fullfilename);
431  fd = file_open(fullfilename, O_RDONLY | O_BINARY);
432 
433  if (fd < 0) {
434  int xerrno = errno;
435  debugs(47, DBG_IMPORTANT, MYNAME << "error opening " << fullfilename << ": " << xstrerr(xerrno));
436  } else
438 
439  continue;
440  }
441 
442  if (td != NULL)
443  closedir(td);
444 
445  td = NULL;
446 
447  in_dir = 0;
448 
449  if (sd->validL2(++curlvl2))
450  continue;
451 
452  curlvl2 = 0;
453 
454  if (sd->validL1(++curlvl1))
455  continue;
456 
457  curlvl1 = 0;
458 
459  done = 1;
460  }
461 
462  *filn_p = fn;
463  return fd;
464 }
465 
466 bool
468 {
469  return false;
470 }
471 
472 bool
474 {
475  return _done;
476 }
477 
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:134
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 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:733
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:157
const char * storeKeyText(const cache_key *key)
int file_open(const char *path, int mode)
Definition: fs_io.cc:46
Controller & Root()
safely access controller singleton
Definition: Controller.cc:850
time_t expires
Definition: Store.h:200
struct timeval current_time
Definition: stub_time.cc:15
int opt_foreground_rebuild
time_t timestamp
Definition: Store.h:198
void rebuildFromDirectory()
process one cache file
void init(mb_size_t szInit, mb_size_t szMax)
Definition: MemBuf.cc:96
static UFSSwapLogParser * GetUFSSwapLogParser(FILE *fp)
char fullfilename[MAXPATHLEN *2]
Definition: RebuildState.h:57
uint64_t swap_file_sz
Definition: Store.h:204
int tvSubMsec(struct timeval, struct timeval)
Definition: stub_time.cc:20
const char * xstrerr(int error)
Definition: xstrerror.cc:83
#define debugs(SECTION, LEVEL, CONTENT)
Definition: Debug.h:124
unsigned char key[SQUID_MD5_DIGEST_LENGTH]
#define true
Definition: GnuRegex.c:234
#define DBG_IMPORTANT
Definition: Debug.h:46
static StoreRebuildData counts
#define SQUID_MD5_DIGEST_LENGTH
Definition: md5.h:66
FILE * fp
Definition: membanger.c:35
bool evictStaleAndContinue(const cache_key *candidateKey, const time_t maxRef, int &staleCount)
static EVH RebuildStep
Definition: RebuildState.h:29
SwappedTime timestamp
StoreRebuildData counts
Definition: RebuildState.h:59
uint16_t flags
Definition: Store.h:206
int getNextFile(sfileno *, int *size)
signed_int32_t sfileno
Definition: forward.h:22
#define SM_PAGE_SIZE
Definition: defines.h:102
StoreEntry * addedEntry(Store::Disk *aStore, String name, String varySpec, String varyKey)
uint16_t refcount
Definition: Store.h:205
void const char * buf
Definition: stub_helper.cc:16
std::ostream & HERE(std::ostream &s)
Definition: Debug.h:153
virtual bool error() const
const char * swap_log_op_str[]
void addIfFresh(const cache_key *key, sfileno file_number, uint64_t swap_file_sz, time_t expires, time_t timestamp, time_t lastref, time_t lastmod, uint32_t refcount, uint16_t flags)
if the loaded entry metadata is still relevant, indexes the entry
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:166
static bool FilenoBelongsHere(int fn, int cachedir, int level1dir, int level2dir)
Definition: UFSSwapDir.cc:1138
RefCount< UFSSwapDir > sd
Definition: RebuildState.h:37
Store::DiskConfig cacheSwap
Definition: SquidConfig.h:419
int store_open_disk_fd
Fs::Ufs::UFSSwapLogParser * LogParser
Definition: RebuildState.h:40
Definition: MemBuf.h:23
void storeRebuildProgress(int sd_index, int total, int sofar)
char fullpath[MAXPATHLEN]
Definition: RebuildState.h:56
time_t lastref
Definition: Store.h:199
#define O_BINARY
Definition: defines.h:204
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

 

Introduction

Documentation

Support

Miscellaneous

Web Site Translations

Mirrors