]>
Commit | Line | Data |
---|---|---|
4d6d905e | 1 | /* |
b8ae064d | 2 | * Copyright (C) 1996-2023 The Squid Software Foundation and contributors |
4d6d905e | 3 | * |
bbc27441 AJ |
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. | |
4d6d905e | 7 | */ |
8 | ||
bbc27441 AJ |
9 | /* DEBUG: section 47 Store Directory Routines */ |
10 | ||
f7f3304a | 11 | #include "squid.h" |
2745fea5 | 12 | #include "fs_io.h" |
67679543 | 13 | #include "globals.h" |
58373ff8 | 14 | #include "RebuildState.h" |
4d5904f7 | 15 | #include "SquidConfig.h" |
2745fea5 | 16 | #include "store/Disks.h" |
fb548aaf | 17 | #include "store_key_md5.h" |
687f5275 | 18 | #include "store_rebuild.h" |
67679543 | 19 | #include "StoreSwapLogData.h" |
5bed43d6 | 20 | #include "tools.h" |
58373ff8 | 21 | #include "UFSSwapLogParser.h" |
4b981814 | 22 | |
074d6a40 AJ |
23 | #include <cerrno> |
24 | #include <cmath> | |
582c2af2 FC |
25 | #if HAVE_SYS_STAT_H |
26 | #include <sys/stat.h> | |
27 | #endif | |
28 | ||
58373ff8 | 29 | CBDATA_NAMESPACED_CLASS_INIT(Fs::Ufs,RebuildState); |
4d6d905e | 30 | |
58373ff8 | 31 | Fs::Ufs::RebuildState::RebuildState(RefCount<UFSSwapDir> aSwapDir) : |
cc8c4af2 AJ |
32 | sd(aSwapDir), |
33 | n_read(0), | |
aee3523a | 34 | LogParser(nullptr), |
cc8c4af2 AJ |
35 | curlvl1(0), |
36 | curlvl2(0), | |
37 | in_dir(0), | |
38 | done(0), | |
39 | fn(0), | |
aee3523a AR |
40 | entry(nullptr), |
41 | td(nullptr), | |
cc8c4af2 AJ |
42 | fromLog(true), |
43 | _done(false), | |
aee3523a | 44 | cbdata(nullptr) |
4d6d905e | 45 | { |
cc8c4af2 | 46 | |
c8f4eac4 | 47 | /* |
48 | * If the swap.state file exists in the cache_dir, then | |
49 | * we'll use commonUfsDirRebuildFromSwapLog(), otherwise we'll | |
50 | * use commonUfsDirRebuildFromDirectory() to open up each file | |
51 | * and suck in the meta data. | |
52 | */ | |
1a6347cd | 53 | int clean = 0; //TODO: change to bool |
c8f4eac4 | 54 | int zeroLengthLog = 0; |
55 | FILE *fp = sd->openTmpSwapLog(&clean, &zeroLengthLog); | |
56 | ||
47f6e231 | 57 | if (fp && !zeroLengthLog) |
58373ff8 | 58 | LogParser = Fs::Ufs::UFSSwapLogParser::GetUFSSwapLogParser(fp); |
47f6e231 | 59 | |
aee3523a | 60 | if (LogParser == nullptr ) { |
c8f4eac4 | 61 | fromLog = false; |
62 | ||
aee3523a | 63 | if (fp != nullptr) |
c8f4eac4 | 64 | fclose(fp); |
65 | ||
66 | } else { | |
26ac0430 | 67 | fromLog = true; |
1a6347cd | 68 | flags.clean = (clean != 0); |
c8f4eac4 | 69 | } |
62e76326 | 70 | |
c8f4eac4 | 71 | if (!clean) |
1a6347cd | 72 | flags.need_to_validate = true; |
c8f4eac4 | 73 | |
8ecbe78d EB |
74 | counts.updateStartTime(current_time); |
75 | ||
786f6516 | 76 | debugs(47, DBG_IMPORTANT, "Rebuilding storage in " << sd->path << " (" << |
d178daf7 | 77 | (clean ? "clean log" : (LogParser ? "dirty log" : "no log")) << ")"); |
4d6d905e | 78 | } |
79 | ||
58373ff8 | 80 | Fs::Ufs::RebuildState::~RebuildState() |
4d6d905e | 81 | { |
d3b3ab85 | 82 | sd->closeTmpSwapLog(); |
47f6e231 | 83 | |
84 | if (LogParser) | |
26ac0430 | 85 | delete LogParser; |
4d6d905e | 86 | } |
87 | ||
88 | void | |
58373ff8 | 89 | Fs::Ufs::RebuildState::RebuildStep(void *data) |
4d6d905e | 90 | { |
d3b3ab85 | 91 | RebuildState *rb = (RebuildState *)data; |
7c44eb08 AR |
92 | if (!reconfiguring) |
93 | rb->rebuildStep(); | |
c8f4eac4 | 94 | |
7c44eb08 AR |
95 | // delay storeRebuildComplete() when reconfiguring to protect storeCleanup() |
96 | if (!rb->isDone() || reconfiguring) | |
cbc676b9 | 97 | eventAdd("storeRebuild", RebuildStep, rb, 0.01, 1); |
c8f4eac4 | 98 | else { |
c8f4eac4 | 99 | storeRebuildComplete(&rb->counts); |
100 | delete rb; | |
101 | } | |
102 | } | |
103 | ||
cbc676b9 | 104 | /// load entries from swap.state or files until we run out of entries or time |
c8f4eac4 | 105 | void |
58373ff8 | 106 | Fs::Ufs::RebuildState::rebuildStep() |
c8f4eac4 | 107 | { |
cbc676b9 AR |
108 | // Balance our desire to maximize the number of entries processed at once |
109 | // (and, hence, minimize overheads and total rebuild time) with a | |
110 | // requirement to also process Coordinator events, disk I/Os, etc. | |
111 | const int maxSpentMsec = 50; // keep small: most RAM I/Os are under 1ms | |
112 | const timeval loopStart = current_time; | |
113 | ||
114 | const int totalEntries = LogParser ? LogParser->SwapLogEntries() : -1; | |
115 | ||
116 | while (!isDone()) { | |
117 | if (fromLog) | |
118 | rebuildFromSwapLog(); | |
119 | else | |
120 | rebuildFromDirectory(); | |
121 | ||
122 | // TODO: teach storeRebuildProgress to handle totalEntries <= 0 | |
123 | if (totalEntries > 0 && (n_read % 4000 == 0)) | |
124 | storeRebuildProgress(sd->index, totalEntries, n_read); | |
125 | ||
126 | if (opt_foreground_rebuild) | |
127 | continue; // skip "few entries at a time" check below | |
128 | ||
129 | getCurrentTime(); | |
130 | const double elapsedMsec = tvSubMsec(loopStart, current_time); | |
131 | if (elapsedMsec > maxSpentMsec || elapsedMsec < 0) { | |
bf95c10a | 132 | debugs(47, 5, "pausing after " << n_read << " entries in " << |
cbc676b9 AR |
133 | elapsedMsec << "ms; " << (elapsedMsec/n_read) << "ms per entry"); |
134 | break; | |
135 | } | |
136 | } | |
4d6d905e | 137 | } |
138 | ||
cbc676b9 | 139 | /// process one cache file |
4d6d905e | 140 | void |
58373ff8 | 141 | Fs::Ufs::RebuildState::rebuildFromDirectory() |
4d6d905e | 142 | { |
c3031d67 | 143 | cache_key key[SQUID_MD5_DIGEST_LENGTH]; |
62e76326 | 144 | |
4d6d905e | 145 | struct stat sb; |
4d6d905e | 146 | int fd = -1; |
bf95c10a | 147 | debugs(47, 3, "DIR #" << sd->index); |
62e76326 | 148 | |
e901206a A |
149 | assert(fd == -1); |
150 | sfileno filn = 0; | |
151 | int size; | |
152 | fd = getNextFile(&filn, &size); | |
153 | ||
154 | if (fd == -2) { | |
786f6516 AR |
155 | debugs(47, DBG_IMPORTANT, "Done scanning " << sd->path << " dir (" << |
156 | n_read << " entries)"); | |
e901206a A |
157 | _done = true; |
158 | return; | |
159 | } else if (fd < 0) { | |
160 | return; | |
161 | } | |
aa1a691e | 162 | |
e901206a A |
163 | assert(fd > -1); |
164 | /* lets get file stats here */ | |
62e76326 | 165 | |
cb4185f1 | 166 | ++n_read; |
786f6516 | 167 | |
e901206a | 168 | if (fstat(fd, &sb) < 0) { |
b69e9ffa AJ |
169 | int xerrno = errno; |
170 | debugs(47, DBG_IMPORTANT, MYNAME << "fstat(FD " << fd << "): " << xstrerr(xerrno)); | |
62e76326 | 171 | file_close(fd); |
cb4185f1 | 172 | --store_open_disk_fd; |
62e76326 | 173 | fd = -1; |
e901206a A |
174 | return; |
175 | } | |
62e76326 | 176 | |
e901206a A |
177 | MemBuf buf; |
178 | buf.init(SM_PAGE_SIZE, SM_PAGE_SIZE); | |
179 | if (!storeRebuildLoadEntry(fd, sd->index, buf, counts)) | |
180 | return; | |
181 | ||
52dce2fe | 182 | const uint64_t expectedSize = sb.st_size > 0 ? |
9d4e9cfb | 183 | static_cast<uint64_t>(sb.st_size) : 0; |
52dce2fe | 184 | |
e901206a | 185 | StoreEntry tmpe; |
52dce2fe AR |
186 | const bool parsed = storeRebuildParseEntry(buf, tmpe, key, counts, |
187 | expectedSize); | |
e901206a A |
188 | |
189 | file_close(fd); | |
cb4185f1 | 190 | --store_open_disk_fd; |
e901206a | 191 | fd = -1; |
62e76326 | 192 | |
52dce2fe AR |
193 | bool accepted = parsed && tmpe.swap_file_sz > 0; |
194 | if (parsed && !accepted) { | |
195 | debugs(47, DBG_IMPORTANT, "WARNING: Ignoring ufs cache entry with " << | |
196 | "unknown size: " << tmpe); | |
197 | accepted = false; | |
198 | } | |
199 | ||
200 | if (!accepted) { | |
e901206a A |
201 | // XXX: shouldn't this be a call to commonUfsUnlink? |
202 | sd->unlinkFile(filn); // should we unlink in all failure cases? | |
203 | return; | |
204 | } | |
205 | ||
4310f8b0 EB |
206 | addIfFresh(key, |
207 | filn, | |
208 | tmpe.swap_file_sz, | |
209 | tmpe.expires, | |
210 | tmpe.timestamp, | |
211 | tmpe.lastref, | |
212 | tmpe.lastModified(), | |
213 | tmpe.refcount, | |
214 | tmpe.flags); | |
215 | } | |
216 | ||
217 | /// if the loaded entry metadata is still relevant, indexes the entry | |
218 | void | |
219 | Fs::Ufs::RebuildState::addIfFresh(const cache_key *key, | |
220 | sfileno file_number, | |
221 | uint64_t swap_file_sz, | |
222 | time_t expires, | |
223 | time_t timestamp, | |
224 | time_t lastref, | |
225 | time_t lastmod, | |
226 | uint32_t refcount, | |
227 | uint16_t newFlags) | |
228 | { | |
229 | if (!evictStaleAndContinue(key, lastref, counts.dupcount)) | |
e901206a A |
230 | return; |
231 | ||
cb4185f1 | 232 | ++counts.objcount; |
4310f8b0 EB |
233 | const auto addedEntry = sd->addDiskRestore(key, |
234 | file_number, | |
235 | swap_file_sz, | |
236 | expires, | |
237 | timestamp, | |
238 | lastref, | |
239 | lastmod, | |
240 | refcount, | |
241 | newFlags, | |
242 | 0 /* XXX: unused */); | |
243 | storeDirSwapLog(addedEntry, SWAP_LOG_ADD); | |
d3b3ab85 | 244 | } |
245 | ||
4310f8b0 EB |
246 | /// Evicts a matching entry if it was last touched before caller's maxRef. |
247 | /// \returns false only if the matching entry was touched at or after maxRef, | |
248 | /// indicating that the caller has supplied outdated maxRef. | |
249 | bool | |
250 | Fs::Ufs::RebuildState::evictStaleAndContinue(const cache_key *candidateKey, const time_t maxRef, int &staleCount) | |
822b78b5 | 251 | { |
4310f8b0 | 252 | if (auto *indexedEntry = Store::Root().peek(candidateKey)) { |
822b78b5 | 253 | |
4310f8b0 EB |
254 | if (indexedEntry->lastref >= maxRef) { |
255 | indexedEntry->abandon("Fs::Ufs::RebuildState::evictStaleAndContinue"); | |
256 | ++counts.clashcount; | |
257 | return false; | |
258 | } | |
259 | ||
260 | ++staleCount; | |
261 | indexedEntry->release(true); // evict previously indexedEntry | |
262 | } | |
263 | ||
264 | return true; | |
822b78b5 | 265 | } |
266 | ||
cbc676b9 | 267 | /// process one swap log entry |
d3b3ab85 | 268 | void |
58373ff8 | 269 | Fs::Ufs::RebuildState::rebuildFromSwapLog() |
d3b3ab85 | 270 | { |
e901206a | 271 | StoreSwapLogData swapData; |
62e76326 | 272 | |
e901206a | 273 | if (LogParser->ReadRecord(swapData) != 1) { |
58373ff8 | 274 | debugs(47, DBG_IMPORTANT, "Done reading " << sd->path << " swaplog (" << n_read << " entries)"); |
e901206a A |
275 | LogParser->Close(); |
276 | delete LogParser; | |
aee3523a | 277 | LogParser = nullptr; |
e901206a A |
278 | _done = true; |
279 | return; | |
280 | } | |
62e76326 | 281 | |
cb4185f1 | 282 | ++n_read; |
62e76326 | 283 | |
3f9d4dc2 | 284 | if (!swapData.sane()) { |
cb4185f1 | 285 | ++counts.invalid; |
e901206a | 286 | return; |
3f9d4dc2 | 287 | } |
62e76326 | 288 | |
e901206a A |
289 | /* |
290 | * BC: during 2.4 development, we changed the way swap file | |
291 | * numbers are assigned and stored. The high 16 bits used | |
292 | * to encode the SD index number. There used to be a call | |
293 | * to storeDirProperFileno here that re-assigned the index | |
294 | * bits. Now, for backwards compatibility, we just need | |
295 | * to mask it off. | |
296 | */ | |
297 | swapData.swap_filen &= 0x00FFFFFF; | |
298 | ||
bf95c10a | 299 | debugs(47, 3, swap_log_op_str[(int) swapData.op] << " " << |
e901206a A |
300 | storeKeyText(swapData.key) << " "<< std::setfill('0') << |
301 | std::hex << std::uppercase << std::setw(8) << | |
302 | swapData.swap_filen); | |
303 | ||
304 | if (swapData.op == SWAP_LOG_ADD) { | |
305 | (void) 0; | |
306 | } else if (swapData.op == SWAP_LOG_DEL) { | |
4310f8b0 EB |
307 | // remove any older or same-age entry; +1 covers same-age entries |
308 | (void)evictStaleAndContinue(swapData.key, swapData.lastref+1, counts.cancelcount); | |
e901206a A |
309 | return; |
310 | } else { | |
311 | const double | |
312 | x = ::log(static_cast<double>(++counts.bad_log_op)) / ::log(10.0); | |
313 | ||
314 | if (0.0 == x - (double) (int) x) | |
58373ff8 | 315 | debugs(47, DBG_IMPORTANT, "WARNING: " << counts.bad_log_op << " invalid swap log entries found"); |
e901206a | 316 | |
cb4185f1 | 317 | ++counts.invalid; |
e901206a A |
318 | |
319 | return; | |
320 | } | |
321 | ||
322 | ++counts.scancount; // XXX: should not this be incremented earlier? | |
323 | ||
324 | if (!sd->validFileno(swapData.swap_filen, 0)) { | |
cb4185f1 | 325 | ++counts.invalid; |
e901206a A |
326 | return; |
327 | } | |
328 | ||
329 | if (EBIT_TEST(swapData.flags, KEY_PRIVATE)) { | |
cb4185f1 | 330 | ++counts.badflags; |
e901206a A |
331 | return; |
332 | } | |
333 | ||
4310f8b0 EB |
334 | if (sd->mapBitTest(swapData.swap_filen)) { |
335 | // While we were scanning the logs, some (unrelated) entry was added to | |
336 | // our disk using our logged swap_filen. We could change our swap_filen | |
337 | // and move the store file, but there is no Store API to do that (TODO). | |
cb4185f1 | 338 | ++counts.clashcount; |
e901206a | 339 | return; |
c6e51aff AR |
340 | } |
341 | ||
4310f8b0 EB |
342 | addIfFresh(swapData.key, |
343 | swapData.swap_filen, | |
344 | swapData.swap_file_sz, | |
345 | swapData.expires, | |
346 | swapData.timestamp, | |
347 | swapData.lastref, | |
348 | swapData.lastmod, | |
349 | swapData.refcount, | |
350 | swapData.flags); | |
c6e51aff AR |
351 | } |
352 | ||
4d6d905e | 353 | int |
ced8def3 | 354 | Fs::Ufs::RebuildState::getNextFile(sfileno * filn_p, int *) |
4d6d905e | 355 | { |
4d6d905e | 356 | int fd = -1; |
4d6d905e | 357 | int dirs_opened = 0; |
bf95c10a | 358 | debugs(47, 3, "flag=" << flags.init << ", " << |
bf8fe701 | 359 | sd->index << ": /"<< std::setfill('0') << std::hex << |
360 | std::uppercase << std::setw(2) << curlvl1 << "/" << std::setw(2) << | |
361 | curlvl2); | |
62e76326 | 362 | |
d3b3ab85 | 363 | if (done) |
62e76326 | 364 | return -2; |
365 | ||
d3b3ab85 | 366 | while (fd < 0 && done == 0) { |
62e76326 | 367 | fd = -1; |
368 | ||
1a6347cd | 369 | if (!flags.init) { /* initialize, open first file */ |
cc8c4af2 | 370 | // XXX: 0's should not be needed, constructor inits now |
62e76326 | 371 | done = 0; |
372 | curlvl1 = 0; | |
373 | curlvl2 = 0; | |
374 | in_dir = 0; | |
1a6347cd | 375 | flags.init = true; |
62e76326 | 376 | assert(Config.cacheSwap.n_configured > 0); |
377 | } | |
378 | ||
58373ff8 | 379 | if (0 == in_dir) { /* we need to read in a new directory */ |
7c964f99 | 380 | fullpath.Printf("%s/%02X/%02X", |
bb4cc8e6 | 381 | sd->path, |
382 | curlvl1, curlvl2); | |
62e76326 | 383 | |
384 | if (dirs_opened) | |
385 | return -1; | |
386 | ||
7c964f99 | 387 | td = opendir(fullpath.c_str()); |
62e76326 | 388 | |
cb4185f1 | 389 | ++dirs_opened; |
62e76326 | 390 | |
b69e9ffa AJ |
391 | if (!td) { |
392 | int xerrno = errno; | |
d816f28d | 393 | debugs(47, DBG_IMPORTANT, "ERROR: " << MYNAME << "in opendir (" << fullpath << "): " << xstrerr(xerrno)); |
62e76326 | 394 | } else { |
58373ff8 | 395 | entry = readdir(td); /* skip . and .. */ |
62e76326 | 396 | entry = readdir(td); |
397 | ||
aee3523a | 398 | if (entry == nullptr && errno == ENOENT) |
bf95c10a | 399 | debugs(47, DBG_IMPORTANT, "WARNING: directory does not exist!"); |
400 | debugs(47, 3, "Directory " << fullpath); | |
62e76326 | 401 | } |
402 | } | |
403 | ||
aee3523a | 404 | if (td != nullptr && (entry = readdir(td)) != nullptr) { |
cb4185f1 | 405 | ++in_dir; |
62e76326 | 406 | |
407 | if (sscanf(entry->d_name, "%x", &fn) != 1) { | |
bf95c10a | 408 | debugs(47, 3, "invalid entry " << entry->d_name); |
62e76326 | 409 | continue; |
410 | } | |
411 | ||
412 | if (!UFSSwapDir::FilenoBelongsHere(fn, sd->index, curlvl1, curlvl2)) { | |
bf95c10a | 413 | debugs(47, 3, std::setfill('0') << |
bf8fe701 | 414 | std::hex << std::uppercase << std::setw(8) << fn << |
415 | " does not belong in " << std::dec << sd->index << "/" << | |
416 | curlvl1 << "/" << curlvl2); | |
417 | ||
62e76326 | 418 | continue; |
419 | } | |
420 | ||
421 | if (sd->mapBitTest(fn)) { | |
bf95c10a | 422 | debugs(47, 3, "Locked, continuing with next."); |
62e76326 | 423 | continue; |
424 | } | |
425 | ||
7c964f99 | 426 | fullfilename.Printf(SQUIDSBUFPH "/%s", |
bb4cc8e6 | 427 | SQUIDSBUFPRINT(fullpath), entry->d_name); |
bf95c10a | 428 | debugs(47, 3, "Opening " << fullfilename); |
7c964f99 | 429 | fd = file_open(fullfilename.c_str(), O_RDONLY | O_BINARY); |
62e76326 | 430 | |
b69e9ffa AJ |
431 | if (fd < 0) { |
432 | int xerrno = errno; | |
d816f28d | 433 | debugs(47, DBG_IMPORTANT, "ERROR: " << MYNAME << "opening " << fullfilename << ": " << xstrerr(xerrno)); |
b69e9ffa | 434 | } else |
cb4185f1 | 435 | ++store_open_disk_fd; |
62e76326 | 436 | |
437 | continue; | |
438 | } | |
439 | ||
aee3523a | 440 | if (td != nullptr) |
62e76326 | 441 | closedir(td); |
442 | ||
aee3523a | 443 | td = nullptr; |
62e76326 | 444 | |
445 | in_dir = 0; | |
446 | ||
447 | if (sd->validL2(++curlvl2)) | |
448 | continue; | |
449 | ||
450 | curlvl2 = 0; | |
451 | ||
452 | if (sd->validL1(++curlvl1)) | |
453 | continue; | |
454 | ||
455 | curlvl1 = 0; | |
456 | ||
457 | done = 1; | |
4d6d905e | 458 | } |
62e76326 | 459 | |
d3b3ab85 | 460 | *filn_p = fn; |
4d6d905e | 461 | return fd; |
462 | } | |
528b2c61 | 463 | |
c8f4eac4 | 464 | bool |
58373ff8 | 465 | Fs::Ufs::RebuildState::error() const |
c8f4eac4 | 466 | { |
467 | return false; | |
468 | } | |
469 | ||
470 | bool | |
58373ff8 | 471 | Fs::Ufs::RebuildState::isDone() const |
c8f4eac4 | 472 | { |
473 | return _done; | |
474 | } | |
475 |