2 * Copyright (C) 1996-2021 The Squid Software Foundation and contributors
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.
9 /* DEBUG: section 20 Store Rebuild Routines */
15 #include "SquidConfig.h"
16 #include "SquidTime.h"
17 #include "StatCounters.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 // for tvSubDsec() which should be in SquidTime.h
29 static StoreRebuildData counts
;
31 static void storeCleanup(void *);
33 // TODO: Either convert to Progress or replace with StoreRebuildData.
34 // TODO: Handle unknown totals (UFS cache_dir that lost swap.state) correctly.
36 /* total number of "swap.state" entries that will be read */
38 /* number of entries read so far */
40 } store_rebuild_progress
;
42 static store_rebuild_progress
*RebuildProgress
= NULL
;
45 StoreRebuildData::updateStartTime(const timeval
&dirStartTime
)
47 startTime
= started() ? std::min(startTime
, dirStartTime
) : dirStartTime
;
53 static int store_errors
= 0;
54 static StoreSearchPointer currentSearch
;
55 static int validated
= 0;
58 if (currentSearch
== NULL
|| currentSearch
->isDone())
59 currentSearch
= Store::Root().search();
61 size_t statCount
= 500;
63 // TODO: Avoid the loop (and ENTRY_VALIDATED) unless opt_store_doublecheck.
64 while (statCount
-- && !currentSearch
->isDone() && currentSearch
->next()) {
67 e
= currentSearch
->currentItem();
71 if (EBIT_TEST(e
->flags
, ENTRY_VALIDATED
))
75 * Calling StoreEntry->release() has no effect because we're
76 * still in 'store_rebuilding' state
81 if (opt_store_doublecheck
)
82 if (e
->disk().doubleCheck(*e
))
85 EBIT_SET(e
->flags
, ENTRY_VALIDATED
);
88 * Only set the file bit if we know its a valid entry
89 * otherwise, set it in the validation procedure
92 if ((++validated
& 0x3FFFF) == 0)
93 /* TODO format the int with with a stream operator */
94 debugs(20, DBG_IMPORTANT
, " " << validated
<< " Entries Validated so far.");
97 if (currentSearch
->isDone()) {
98 debugs(20, 2, "Seen: " << seen
<< " entries");
99 debugs(20, DBG_IMPORTANT
, " Completed Validation Procedure");
100 debugs(20, DBG_IMPORTANT
, " Validated " << validated
<< " Entries");
101 debugs(20, DBG_IMPORTANT
, " store_swap_size = " << Store::Root().currentSize() / 1024.0 << " KB");
102 --StoreController::store_dirs_rebuilding
;
103 assert(0 == StoreController::store_dirs_rebuilding
);
105 if (opt_store_doublecheck
&& store_errors
) {
106 fatalf("Quitting after finding %d cache index inconsistencies. " \
107 "Removing cache index will force its slow rebuild. " \
108 "Removing -S will let Squid start with an inconsistent " \
109 "cache index (at your own risk).\n", store_errors
);
113 storeDigestNoteStoreReady();
115 currentSearch
= NULL
;
117 eventAdd("storeCleanup", storeCleanup
, NULL
, 0.0, 1);
120 /* meta data recreated from disk image in swap directory */
123 storeRebuildComplete(StoreRebuildData
*dc
)
126 counts
.objcount
+= dc
->objcount
;
127 counts
.expcount
+= dc
->expcount
;
128 counts
.scancount
+= dc
->scancount
;
129 counts
.clashcount
+= dc
->clashcount
;
130 counts
.dupcount
+= dc
->dupcount
;
131 counts
.cancelcount
+= dc
->cancelcount
;
132 counts
.invalid
+= dc
->invalid
;
133 counts
.badflags
+= dc
->badflags
;
134 counts
.bad_log_op
+= dc
->bad_log_op
;
135 counts
.zero_object_sz
+= dc
->zero_object_sz
;
136 counts
.validations
+= dc
->validations
;
137 counts
.updateStartTime(dc
->startTime
);
139 // else the caller was not responsible for indexing its cache_dir
141 assert(StoreController::store_dirs_rebuilding
> 1);
142 --StoreController::store_dirs_rebuilding
;
145 * When store_dirs_rebuilding == 1, it means we are done reading
146 * or scanning all cache_dirs. Now report the stats and start
147 * the validation (storeCleanup()) thread.
150 if (StoreController::store_dirs_rebuilding
> 1)
153 const auto dt
= tvSubDsec(counts
.startTime
, current_time
);
155 debugs(20, DBG_IMPORTANT
, "Finished rebuilding storage from disk.");
156 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.scancount
<< " Entries scanned");
157 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.invalid
<< " Invalid entries.");
158 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.badflags
<< " With invalid flags.");
159 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.objcount
<< " Objects loaded.");
160 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.expcount
<< " Objects expired.");
161 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.cancelcount
<< " Objects cancelled.");
162 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.dupcount
<< " Duplicate URLs purged.");
163 debugs(20, DBG_IMPORTANT
, " " << std::setw(7) << counts
.clashcount
<< " Swapfile clashes avoided.");
164 debugs(20, DBG_IMPORTANT
, " Took "<< std::setw(3)<< std::setprecision(2) << dt
<< " seconds ("<< std::setw(6) <<
165 ((double) counts
.objcount
/ (dt
> 0.0 ? dt
: 1.0)) << " objects/sec).");
166 debugs(20, DBG_IMPORTANT
, "Beginning Validation Procedure");
168 eventAdd("storeCleanup", storeCleanup
, NULL
, 0.0, 1);
170 xfree(RebuildProgress
);
172 RebuildProgress
= NULL
;
176 * this is ugly. We don't actually start any rebuild threads here,
177 * but only initialize counters, etc. The rebuild threads are
178 * actually started by the filesystem "fooDirInit" function.
181 storeRebuildStart(void)
183 counts
= StoreRebuildData(); // reset counters
185 * Note: store_dirs_rebuilding is initialized to 1.
187 * When we parse the configuration and construct each swap dir,
188 * the construction of that raises the rebuild count.
190 * This prevents us from trying to write clean logs until we
191 * finished rebuilding - including after a reconfiguration that opens an
192 * existing swapdir. The corresponding decrement * occurs in
193 * storeCleanup(), when it is finished.
195 RebuildProgress
= (store_rebuild_progress
*)xcalloc(Config
.cacheSwap
.n_configured
,
196 sizeof(store_rebuild_progress
));
200 * A fs-specific rebuild procedure periodically reports its
204 storeRebuildProgress(int sd_index
, int total
, int sofar
)
206 static time_t last_report
= 0;
207 // TODO: Switch to int64_t and fix handling of unknown totals.
214 if (sd_index
>= Config
.cacheSwap
.n_configured
)
217 if (NULL
== RebuildProgress
)
220 RebuildProgress
[sd_index
].total
= total
;
222 RebuildProgress
[sd_index
].scanned
= sofar
;
224 if (squid_curtime
- last_report
< 15)
227 for (sd_index
= 0; sd_index
< Config
.cacheSwap
.n_configured
; ++sd_index
) {
228 n
+= (double) RebuildProgress
[sd_index
].scanned
;
229 d
+= (double) RebuildProgress
[sd_index
].total
;
232 debugs(20, DBG_IMPORTANT
, "Indexing cache entries: " << Progress(n
, d
));
233 last_report
= squid_curtime
;
237 Progress::print(std::ostream
&os
) const
240 const auto savedPrecision
= os
.precision(2);
241 const auto percent
= 100.0 * completed
/ goal
;
242 os
<< percent
<< "% (" << completed
<< " out of " << goal
<< ")";
243 (void)os
.precision(savedPrecision
);
244 } else if (!completed
&& !goal
) {
245 os
<< "nothing to do";
247 // unknown (i.e. negative) or buggy (i.e. zero when completed != 0) goal
254 #include "StoreMeta.h"
255 #include "StoreMetaUnpacker.h"
257 struct InitStoreEntry
: public unary_function
<StoreMeta
, void> {
258 InitStoreEntry(StoreEntry
*anEntry
, cache_key
*aKey
):what(anEntry
),index(aKey
) {}
260 void operator()(StoreMeta
const &x
) {
261 switch (x
.getType()) {
264 assert(x
.length
== SQUID_MD5_DIGEST_LENGTH
);
265 memcpy(index
, x
.value
, SQUID_MD5_DIGEST_LENGTH
);
278 tmp
= (struct old_metahdr
*)x
.value
;
279 assert(x
.length
== STORE_HDR_METASIZE_OLD
);
280 what
->timestamp
= tmp
->timestamp
;
281 what
->lastref
= tmp
->lastref
;
282 what
->expires
= tmp
->expires
;
283 what
->lastModified(tmp
->lastmod
);
284 what
->swap_file_sz
= tmp
->swap_file_sz
;
285 what
->refcount
= tmp
->refcount
;
286 what
->flags
= tmp
->flags
;
289 case STORE_META_STD_LFS
:
290 assert(x
.length
== STORE_HDR_METASIZE
);
291 memcpy(&what
->timestamp
, x
.value
, STORE_HDR_METASIZE
);
304 storeRebuildLoadEntry(int fd
, int diskIndex
, MemBuf
&buf
, StoreRebuildData
&)
309 assert(buf
.hasSpace()); // caller must allocate
311 const int len
= FD_READ_METHOD(fd
, buf
.space(), buf
.spaceSize());
312 ++ statCounter
.syscalls
.disk
.reads
;
314 const int xerrno
= errno
;
315 debugs(47, DBG_IMPORTANT
, "WARNING: cache_dir[" << diskIndex
<< "]: " <<
316 "Ignoring cached entry after meta data read failure: " << xstrerr(xerrno
));
325 storeRebuildParseEntry(MemBuf
&buf
, StoreEntry
&tmpe
, cache_key
*key
,
326 StoreRebuildData
&stats
,
327 uint64_t expectedSize
)
329 int swap_hdr_len
= 0;
330 StoreMetaUnpacker
aBuilder(buf
.content(), buf
.contentSize(), &swap_hdr_len
);
331 if (aBuilder
.isBufferZero()) {
332 debugs(47,5, HERE
<< "skipping empty record.");
336 StoreMeta
*tlv_list
= nullptr;
338 tlv_list
= aBuilder
.createStoreMeta();
339 } catch (const std::exception
&e
) {
340 debugs(47, DBG_IMPORTANT
, "WARNING: Ignoring store entry because " << e
.what());
345 // TODO: consume parsed metadata?
347 debugs(47,7, "successful swap meta unpacking; swap_file_sz=" << tmpe
.swap_file_sz
);
348 memset(key
, '\0', SQUID_MD5_DIGEST_LENGTH
);
350 InitStoreEntry
visitor(&tmpe
, key
);
351 for_each(*tlv_list
, visitor
);
352 storeSwapTLVFree(tlv_list
);
355 if (storeKeyNull(key
)) {
356 debugs(47, DBG_IMPORTANT
, "WARNING: Ignoring keyless cache entry");
363 if (expectedSize
> 0) {
364 if (tmpe
.swap_file_sz
== 0) {
365 tmpe
.swap_file_sz
= expectedSize
;
366 } else if (tmpe
.swap_file_sz
== (uint64_t)(expectedSize
- swap_hdr_len
)) {
367 tmpe
.swap_file_sz
= expectedSize
;
368 } else if (tmpe
.swap_file_sz
!= expectedSize
) {
369 debugs(47, DBG_IMPORTANT
, "WARNING: Ignoring cache entry due to a " <<
370 "SIZE MISMATCH " << tmpe
.swap_file_sz
<< "!=" << expectedSize
);
373 } else if (tmpe
.swap_file_sz
<= 0) {
374 // if caller cannot handle unknown sizes, it must check after the call.
375 debugs(47, 7, "unknown size: " << tmpe
);
378 if (EBIT_TEST(tmpe
.flags
, KEY_PRIVATE
)) {