diff --git a/src/SquidConfig.h b/src/SquidConfig.h index 8e72ceda3b0..ecdf35d508f 100644 --- a/src/SquidConfig.h +++ b/src/SquidConfig.h @@ -324,6 +324,7 @@ class SquidConfig int httpd_suppress_version_string; int global_internal_static; int collapsed_forwarding; + int paranoid_hit_validation; #if FOLLOW_X_FORWARDED_FOR int acl_uses_indirect_client; diff --git a/src/cf.data.pre b/src/cf.data.pre index 1422b23ae38..031ed9ae2b8 100644 --- a/src/cf.data.pre +++ b/src/cf.data.pre @@ -4006,6 +4006,23 @@ DOC_START cache_dir rock /ssd3 ... max-size=99999 DOC_END +NAME: paranoid_hit_validation +COMMENT: on|off +TYPE: onoff +DEFAULT: off +LOC: Config.onoff.paranoid_hit_validation +DOC_START + Controls whether Squid should perform paranoid validation of + cache entry metadata integrity every time a cache entry is hit. + Squid bugs notwithstanding, 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). + + Enabling this feature also results in periodic reports of + validation statistics dumped to cache.log. +DOC_END + NAME: max_open_disk_fds TYPE: int LOC: Config.max_open_disk_fds diff --git a/src/ipc/ReadWriteLock.cc b/src/ipc/ReadWriteLock.cc index 4a0a86e298f..d197bd7af30 100644 --- a/src/ipc/ReadWriteLock.cc +++ b/src/ipc/ReadWriteLock.cc @@ -147,3 +147,11 @@ Ipc::ReadWriteLockStats::dump(StoreEntry &e) const } } +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 +} diff --git a/src/ipc/ReadWriteLock.h b/src/ipc/ReadWriteLock.h index 1266f912ce4..1c18d3a7f76 100644 --- a/src/ipc/ReadWriteLock.h +++ b/src/ipc/ReadWriteLock.h @@ -52,6 +52,9 @@ class ReadWriteLock std::atomic 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 { diff --git a/src/ipc/StoreMap.cc b/src/ipc/StoreMap.cc index f7320d435a8..42d079daacb 100644 --- a/src/ipc/StoreMap.cc +++ b/src/ipc/StoreMap.cc @@ -11,6 +11,7 @@ #include "squid.h" #include "ipc/StoreMap.h" #include "sbuf/SBuf.h" +#include "SquidConfig.h" #include "Store.h" #include "store_key_md5.h" #include "tools.h" @@ -355,19 +356,15 @@ Ipc::StoreMap::openForReading(const cache_key *const key, sfileno &fileno) 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 Anchor *slot = openForReadingAt(idx, key)) { + fileno = idx; + return slot; // 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); @@ -392,6 +389,20 @@ Ipc::StoreMap::openForReadingAt(const sfileno 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.onoff.paranoid_hit_validation && !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; } @@ -425,13 +436,7 @@ Ipc::StoreMap::openForUpdating(Update &update, const sfileno fileNoHint) // 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; } @@ -655,6 +660,85 @@ Ipc::StoreMap::validSlice(const int pos) const return 0 <= pos && pos < sliceLimit(); } +bool +Ipc::StoreMap::validateHit(const sfileno fileno) +{ + static uint64_t validationAttempts = 0; + static uint64_t validationRefusalsDueToLocking = 0; + static uint64_t validationRefusalsDueToZeroSize = 0; + static uint64_t validationFailures = 0; + + static time_t reportingGap = 1*60*60; // 1 hour + static time_t reportingDeadline = squid_curtime + reportingGap; + if (squid_curtime >= reportingDeadline) { + reportingDeadline = squid_curtime + reportingGap; // sliding OK + + debugs(54, DBG_IMPORTANT, "FYI: paranoid_hit_validation stats:\n" << + " attempts=" << validationAttempts << "\n" << + " refusalsDueToLocking=" << validationRefusalsDueToLocking << "\n" << + " refusalsDueToZeroSize=" << validationRefusalsDueToZeroSize << "\n" << + " failures=" << validationFailures << "\n"); + } + + const auto &anchor = anchorAt(fileno); + + ++validationAttempts; + + if (!anchor.lock.lockHeaders()) { + ++validationRefusalsDueToLocking; + 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; + } + + anchor.lock.unlockHeaders(); + + if (actualByteCount == expectedByteCount && lastSeenSlice < 0) + return true; + + if (!anchor.basics.swap_file_sz) { + ++validationRefusalsDueToZeroSize; + return true; // presume valid; cannot validate w/o known swap_file_sz + } + + ++validationFailures; + + 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(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) { diff --git a/src/ipc/StoreMap.h b/src/ipc/StoreMap.h index b205aad28b2..0f36abe6a3d 100644 --- a/src/ipc/StoreMap.h +++ b/src/ipc/StoreMap.h @@ -256,7 +256,7 @@ class StoreMap /// 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); @@ -280,6 +280,10 @@ class StoreMap /// 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); + /// copies slice to its designated position void importSlice(const SliceId sliceId, const Slice &slice);