#include "store/Disk.h"
#include "store/forward.h"
+#include <chrono>
+
#if USE_OPENSSL
class sslproxy_cert_sign;
class sslproxy_cert_adapt;
int forward_max_tries;
int connect_retries;
+ std::chrono::nanoseconds paranoid_hit_validation;
+
class ACL *aclList;
struct {
int outs = 0;
int ins = 0;
} swap;
+
+ struct {
+ uint64_t attempts = 0;
+ uint64_t refusalsDueToLocking = 0;
+ uint64_t refusalsDueToZeroSize = 0;
+ uint64_t refusalsDueToTimeLimit = 0;
+ uint64_t failures = 0;
+ } hitValidation;
+
};
extern StatCounters statCounter;
Must(!map);
map = new TransientsMap(MapLabel);
map->cleaner = this;
+ map->disableHitValidation(); // Transients lacks slices to validate
locals = new Locals(entryLimit, 0);
}
*var = 0;
}
-#if UNUSED_CODE
-// TODO: add a parameter with 'time_nanoseconds' TYPE and uncomment
static void
dump_time_nanoseconds(StoreEntry *entry, const char *name, const std::chrono::nanoseconds &var)
{
{
*var = std::chrono::nanoseconds::zero();
}
-#endif
#if UNUSED_CODE
static void
string
time_msec
time_t
+time_nanoseconds
tristate
uri_whitespace
UrlHelperTimeout acl
cache_dir rock /ssd3 ... max-size=99999
DOC_END
+NAME: paranoid_hit_validation
+COMMENT: time-units-small
+TYPE: time_nanoseconds
+DEFAULT: 0
+DEFAULT_DOC: validation disabled
+LOC: Config.paranoid_hit_validation
+DOC_START
+ Controls whether Squid should perform paranoid validation of cache entry
+ metadata integrity every time a cache entry is hit. This low-level
+ validation should always succeed. Each failed validation results in a
+ cache miss, a BUG line reported to cache.log, and the invalid entry
+ marked as unusable (and eventually purged from the cache).
+
+ Squid can only validate shared cache memory and rock cache_dir entries.
+
+ * Zero (default) value means that the validation is disabled.
+
+ * Positive values enable validation:
+ - values less than 1 day approximate the maximum time that Squid is allowed
+ to spend validating a single cache hit.
+ - values greater or equal to 1 day are considered as no limitation:
+ in this case all checks will be performed, regardless of how much time
+ they take.
+
+ Hits are usually stored using 16KB slots (for rock, the size is
+ configurable via cache_dir slot-size). Larger hits require scanning more
+ slots and, hence, take more time. When validation is enabled, at least one
+ slot is always validated, regardless of the configured time limit.
+
+ A worker process validating an entry cannot do anything else (i.e. the
+ validation is blocking). The validation overhead is environment dependent,
+ but developers have observed Squid spending 3-10 microseconds to check each
+ slot of a Rock or shared memory hit entry. If Squid cuts validation short
+ because it runs out of configured time, it treats the entry as valid.
+
+ When hit validation is enabled, its statistics is included in Cache
+ Manager mgr:counters, mgr:5min, and mgr:60min reports.
+DOC_END
+
NAME: max_open_disk_fds
TYPE: int
LOC: Config.max_open_disk_fds
}
}
+std::ostream &
+Ipc::operator <<(std::ostream &os, const Ipc::ReadWriteLock &lock)
+{
+ return os << lock.readers << 'R' <<
+ (lock.writing ? "W" : "") <<
+ (lock.appending ? "A" : "");
+ // impossible to report lock.updating without setting/clearing that flag
+}
+
#define SQUID_IPC_READ_WRITE_LOCK_H
#include <atomic>
+#include <iosfwd>
class StoreEntry;
std::atomic<uint32_t> writeLevel; ///< number of users writing (or trying to write)
};
+/// dumps approximate lock state (for debugging)
+std::ostream &operator <<(std::ostream &os, const Ipc::ReadWriteLock &);
+
/// approximate stats of a set of ReadWriteLocks
class ReadWriteLockStats
{
#include "squid.h"
#include "ipc/StoreMap.h"
#include "sbuf/SBuf.h"
+#include "SquidConfig.h"
+#include "StatCounters.h"
#include "Store.h"
#include "store/Controller.h"
#include "store_key_md5.h"
#include "tools.h"
+#include <chrono>
+
static SBuf
StoreMapSlicesId(const SBuf &path)
{
Ipc::StoreMap::StoreMap(const SBuf &aPath): cleaner(NULL), path(aPath),
fileNos(shm_old(FileNos)(StoreMapFileNosId(path).c_str())),
anchors(shm_old(Anchors)(StoreMapAnchorsId(path).c_str())),
- slices(shm_old(Slices)(StoreMapSlicesId(path).c_str()))
+ slices(shm_old(Slices)(StoreMapSlicesId(path).c_str())),
+ hitValidation(true)
{
debugs(54, 5, "attached " << path << " with " <<
fileNos->capacity << '+' <<
debugs(54, 5, "opening entry with key " << storeKeyText(key)
<< " for reading " << path);
const int idx = fileNoByKey(key);
- if (const Anchor *slot = openForReadingAt(idx)) {
- if (slot->sameKey(key)) {
- fileno = idx;
- return slot; // locked for reading
- }
- slot->lock.unlockShared();
- debugs(54, 7, "closed wrong-key entry " << idx << " for reading " << path);
+ if (const auto anchor = openForReadingAt(idx, key)) {
+ fileno = idx;
+ return anchor; // locked for reading
}
return NULL;
}
const Ipc::StoreMap::Anchor *
-Ipc::StoreMap::openForReadingAt(const sfileno fileno)
+Ipc::StoreMap::openForReadingAt(const sfileno fileno, const cache_key *const key)
{
debugs(54, 5, "opening entry " << fileno << " for reading " << path);
Anchor &s = anchorAt(fileno);
return NULL;
}
+ if (!s.sameKey(key)) {
+ s.lock.unlockShared();
+ debugs(54, 5, "cannot open wrong-key entry " << fileno <<
+ " for reading " << path);
+ return nullptr;
+ }
+
+ if (Config.paranoid_hit_validation.count() && hitValidation && !validateHit(fileno)) {
+ s.lock.unlockShared();
+ debugs(54, 5, "cannot open corrupted entry " << fileno <<
+ " for reading " << path);
+ return nullptr;
+ }
+
debugs(54, 5, "opened entry " << fileno << " for reading " << path);
return &s;
}
// Unreadable entries cannot (e.g., empty and otherwise problematic entries)
// or should not (e.g., entries still forming their metadata) be updated.
- if (const Anchor *anchor = openForReadingAt(update.stale.fileNo)) {
- if (!anchor->sameKey(key)) {
- closeForReading(update.stale.fileNo);
- debugs(54, 5, "cannot open wrong-key entry " << update.stale.fileNo << " for updating " << path);
- return false;
- }
- } else {
+ if (!openForReadingAt(update.stale.fileNo, key)) {
debugs(54, 5, "cannot open unreadable entry " << update.stale.fileNo << " for updating " << path);
return false;
}
return 0 <= pos && pos < sliceLimit();
}
+/// Checks whether the object lifetime has exceeded the specified maximum.
+/// The lifetime is considered to exceed the maximum if the time goes backwards.
+/// Uses the highest precision provided by the C++ implementation.
+class ConservativeTimer
+{
+public:
+ typedef std::chrono::high_resolution_clock Clock;
+
+ explicit ConservativeTimer(const Clock::duration max):
+ startTime(Clock::now()),
+ lastTime(startTime),
+ maxTime(startTime + max) {}
+
+ /// whether the current time reached the provided maximum time
+ bool expired() {
+ const auto currentTime = Clock::now();
+ if (currentTime < lastTime) // time went backwards
+ return true;
+ lastTime = currentTime;
+ return lastTime > maxTime;
+ }
+
+private:
+ /// the object creation time
+ Clock::time_point startTime;
+ /// the time of the last expired() call, initially equals to startTime
+ Clock::time_point lastTime;
+ /// after going past this point in time, expired() becomes true
+ const Clock::time_point maxTime;
+};
+
+bool
+Ipc::StoreMap::validateHit(const sfileno fileno)
+{
+ ConservativeTimer timer(Config.paranoid_hit_validation);
+ const auto timeIsLimited = Config.paranoid_hit_validation < std::chrono::hours(24);
+
+ const auto &anchor = anchorAt(fileno);
+
+ ++statCounter.hitValidation.attempts;
+
+ if (!anchor.basics.swap_file_sz) {
+ ++statCounter.hitValidation.refusalsDueToZeroSize;
+ return true; // presume valid; cannot validate w/o known swap_file_sz
+ }
+
+ if (!anchor.lock.lockHeaders()) {
+ ++statCounter.hitValidation.refusalsDueToLocking;
+ return true; // presume valid; cannot validate changing entry
+ }
+
+ const uint64_t expectedByteCount = anchor.basics.swap_file_sz;
+
+ size_t actualSliceCount = 0;
+ uint64_t actualByteCount = 0;
+ SliceId lastSeenSlice = anchor.start;
+ while (lastSeenSlice >= 0) {
+ ++actualSliceCount;
+ if (!validSlice(lastSeenSlice))
+ break;
+ const auto &slice = sliceAt(lastSeenSlice);
+ actualByteCount += slice.size;
+ if (actualByteCount > expectedByteCount)
+ break;
+ lastSeenSlice = slice.next;
+ if (timeIsLimited && timer.expired()) {
+ anchor.lock.unlockHeaders();
+ ++statCounter.hitValidation.refusalsDueToTimeLimit;
+ return true;
+ }
+ }
+
+ anchor.lock.unlockHeaders();
+
+ if (actualByteCount == expectedByteCount && lastSeenSlice < 0)
+ return true;
+
+ ++statCounter.hitValidation.failures;
+
+ debugs(54, DBG_IMPORTANT, "BUG: purging corrupted cache entry " << fileno <<
+ " from " << path <<
+ " expected swap_file_sz=" << expectedByteCount <<
+ " actual swap_file_sz=" << actualByteCount <<
+ " actual slices=" << actualSliceCount <<
+ " last slice seen=" << lastSeenSlice << "\n" <<
+ " key=" << storeKeyText(reinterpret_cast<const cache_key*>(anchor.key)) << "\n" <<
+ " tmestmp=" << anchor.basics.timestamp << "\n" <<
+ " lastref=" << anchor.basics.lastref << "\n" <<
+ " expires=" << anchor.basics.expires << "\n" <<
+ " lastmod=" << anchor.basics.lastmod << "\n" <<
+ " refcount=" << anchor.basics.refcount << "\n" <<
+ " flags=0x" << std::hex << anchor.basics.flags << std::dec << "\n" <<
+ " start=" << anchor.start << "\n" <<
+ " splicingPoint=" << anchor.splicingPoint << "\n" <<
+ " lock=" << anchor.lock << "\n" <<
+ " waitingToBeFreed=" << (anchor.waitingToBeFreed ? 1 : 0) << "\n"
+ );
+ freeEntry(fileno);
+ return false;
+}
+
Ipc::StoreMap::Anchor&
Ipc::StoreMap::anchorAt(const sfileno fileno)
{
/// opens entry (identified by key) for reading, increments read level
const Anchor *openForReading(const cache_key *const key, sfileno &fileno);
/// opens entry (identified by sfileno) for reading, increments read level
- const Anchor *openForReadingAt(const sfileno fileno);
+ const Anchor *openForReadingAt(const sfileno, const cache_key *const);
/// closes open entry after reading, decrements read level
void closeForReading(const sfileno fileno);
/// same as closeForReading() but also frees the entry if it is unlocked
/// either finds and frees an entry with at least 1 slice or returns false
bool purgeOne();
+ /// validates locked hit metadata and calls freeEntry() for invalid entries
+ /// \returns whether hit metadata is correct
+ bool validateHit(const sfileno);
+
+ void disableHitValidation() { hitValidation = false; }
+
/// copies slice to its designated position
void importSlice(const SliceId sliceId, const Slice &slice);
void freeChain(const sfileno fileno, Anchor &inode, const bool keepLock);
void freeChainAt(SliceId sliceId, const SliceId splicingPoint);
+
+ /// whether paranoid_hit_validation should be performed
+ bool hitValidation;
};
/// API for adjusting external state when dirty map slice is being freed
swap_ins += stats.swap_ins;
swap_files_cleaned += stats.swap_files_cleaned;
aborted_requests += stats.aborted_requests;
+ hitValidationAttempts += stats.hitValidationAttempts;
+ hitValidationRefusalsDueToLocking += stats.hitValidationRefusalsDueToLocking;
+ hitValidationRefusalsDueToZeroSize += stats.hitValidationRefusalsDueToZeroSize;
+ hitValidationRefusalsDueToTimeLimit += stats.hitValidationRefusalsDueToTimeLimit;
+ hitValidationFailures += stats.hitValidationFailures;
return *this;
}
double swap_ins;
double swap_files_cleaned;
double aborted_requests;
+ double hitValidationAttempts;
+ double hitValidationRefusalsDueToLocking;
+ double hitValidationRefusalsDueToZeroSize;
+ double hitValidationRefusalsDueToTimeLimit;
+ double hitValidationFailures;
};
/// implement aggregated 'counters' action
swap_ins += stats.swap_ins;
swap_files_cleaned += stats.swap_files_cleaned;
aborted_requests += stats.aborted_requests;
+ hitValidationAttempts += stats.hitValidationAttempts;
+ hitValidationRefusalsDueToLocking += stats.hitValidationRefusalsDueToLocking;
+ hitValidationRefusalsDueToZeroSize += stats.hitValidationRefusalsDueToZeroSize;
+ hitValidationRefusalsDueToTimeLimit += stats.hitValidationRefusalsDueToTimeLimit;
+ hitValidationFailures += stats.hitValidationFailures;
syscalls_disk_opens += stats.syscalls_disk_opens;
syscalls_disk_closes += stats.syscalls_disk_closes;
syscalls_disk_reads += stats.syscalls_disk_reads;
double swap_ins;
double swap_files_cleaned;
double aborted_requests;
+ double hitValidationAttempts;
+ double hitValidationRefusalsDueToLocking;
+ double hitValidationRefusalsDueToZeroSize;
+ double hitValidationRefusalsDueToTimeLimit;
+ double hitValidationFailures;
double syscalls_disk_opens;
double syscalls_disk_closes;
double syscalls_disk_reads;
stats.swap_files_cleaned = XAVG(swap.files_cleaned);
stats.aborted_requests = XAVG(aborted_requests);
+ stats.hitValidationAttempts = XAVG(hitValidation.attempts);
+ stats.hitValidationRefusalsDueToLocking = XAVG(hitValidation.refusalsDueToLocking);
+ stats.hitValidationRefusalsDueToZeroSize = XAVG(hitValidation.refusalsDueToZeroSize);
+ stats.hitValidationRefusalsDueToTimeLimit = XAVG(hitValidation.refusalsDueToTimeLimit);
+ stats.hitValidationFailures = XAVG(hitValidation.failures);
+
stats.syscalls_disk_opens = XAVG(syscalls.disk.opens);
stats.syscalls_disk_closes = XAVG(syscalls.disk.closes);
stats.syscalls_disk_reads = XAVG(syscalls.disk.reads);
storeAppendPrintf(sentry, "aborted_requests = %f/sec\n",
stats.aborted_requests);
+ storeAppendPrintf(sentry, "hit_validation.attempts = %f/sec\n",
+ stats.hitValidationAttempts);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_locking = %f/sec\n",
+ stats.hitValidationRefusalsDueToLocking);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_zeroSize = %f/sec\n",
+ stats.hitValidationRefusalsDueToZeroSize);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_timeLimit = %f/sec\n",
+ stats.hitValidationRefusalsDueToTimeLimit);
+ storeAppendPrintf(sentry, "hit_validation.failures = %f/sec\n",
+ stats.hitValidationFailures);
+
#if USE_POLL
storeAppendPrintf(sentry, "syscalls.polls = %f/sec\n", stats.syscalls_selects);
#elif defined(USE_SELECT) || defined(USE_SELECT_WIN32)
stats.swap_ins = f->swap.ins;
stats.swap_files_cleaned = f->swap.files_cleaned;
stats.aborted_requests = f->aborted_requests;
+
+ stats.hitValidationAttempts = f->hitValidation.attempts;
+ stats.hitValidationRefusalsDueToLocking = f->hitValidation.refusalsDueToLocking;
+ stats.hitValidationRefusalsDueToZeroSize = f->hitValidation.refusalsDueToZeroSize;
+ stats.hitValidationRefusalsDueToTimeLimit = f->hitValidation.refusalsDueToTimeLimit;
+ stats.hitValidationFailures = f->hitValidation.failures;
}
void
stats.swap_files_cleaned);
storeAppendPrintf(sentry, "aborted_requests = %.0f\n",
stats.aborted_requests);
+
+ storeAppendPrintf(sentry, "hit_validation.attempts = %.0f\n",
+ stats.hitValidationAttempts);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_locking = %.0f\n",
+ stats.hitValidationRefusalsDueToLocking);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_zeroSize = %.0f\n",
+ stats.hitValidationRefusalsDueToZeroSize);
+ storeAppendPrintf(sentry, "hit_validation.refusals.due_to_timeLimit = %.0f\n",
+ stats.hitValidationRefusalsDueToTimeLimit);
+ storeAppendPrintf(sentry, "hit_validation.failures = %.0f\n",
+ stats.hitValidationFailures);
}
void
projects / thirdparty / squid.git / commitdiff
