HTTP: MUST ignore a [revalidation] response with an older Date header.

Before this patch, Squid violated the RFC 7234 section 4 MUST
requirement: "When more than one suitable response is stored, a cache
MUST use the most recent response (as determined by the Date header
field)." This problem may be damaging in cache hierarchies where
parent caches may have different responses. Trusting the older response
may lead to excessive IMS requests, cache thrashing and other problems.

diff --git a/src/HttpReply.cc b/src/HttpReply.cc
index 9a6b0f152955580f6da152cee95113e1a70baea0..4bb24c4ec4e7f477955c97e51dff21531b49a3de 100644 (file)
--- a/src/HttpReply.cc
+++ b/src/HttpReply.cc
@@ -627,3 +627,11 @@ String HttpReply::removeStaleWarningValues(const String &value)
     return newValue;
 }
 
+bool
+HttpReply::olderThan(const HttpReply *them) const
+{
+    if (!them || !them->date || !date)
+        return false;
+    return date < them->date;
+}
+

diff --git a/src/HttpReply.h b/src/HttpReply.h
index 1fe8bebc5d867ba41282a112149a6ec8e34d1bb2..f3a911e9bf41a8e7140593bd9ac1d99abe398bf0 100644 (file)
--- a/src/HttpReply.h
+++ b/src/HttpReply.h
@@ -112,6 +112,10 @@ public:
 
     virtual void hdrCacheInit();
 
+    /// whether our Date header value is smaller than theirs
+    /// \returns false if any information is missing
+    bool olderThan(const HttpReply *them) const;
+
 private:
     /** initialize */
     void init();

diff --git a/src/LogTags.cc b/src/LogTags.cc
index f2b5e40a09408931527a6e3a028c69081ee33ee4..3e43b9a85010ca20b1f9414040ada49dc5a42bbb 100644 (file)
--- a/src/LogTags.cc
+++ b/src/LogTags.cc
@@ -55,6 +55,9 @@ LogTags::c_str() const
     else
         pos += snprintf(buf, sizeof(buf), "NONE");
 
+    if (err.ignored)
+        pos += snprintf(buf+pos,sizeof(buf)-pos, "_IGNORED");
+
     // error tags
     if (err.timedout)
         pos += snprintf(buf+pos,sizeof(buf)-pos, "_TIMEDOUT");

diff --git a/src/LogTags.h b/src/LogTags.h
index 635ee41d6f708bb71a3064515b00b69f4187c069..c31082e17360718b15aa94682c664c943ff9a8e5 100644 (file)
--- a/src/LogTags.h
+++ b/src/LogTags.h
@@ -49,6 +49,8 @@ class LogTags
 {
 public:
     LogTags(LogTags_ot t) : oldType(t) {assert(oldType < LOG_TYPE_MAX);}
+    // XXX: this operator does not reset flags
+    // TODO: either replace with a category-only setter or remove
     LogTags &operator =(const LogTags_ot &t) {assert(t < LOG_TYPE_MAX); oldType = t; return *this;}
 
     /// compute the status access.log field
@@ -57,12 +59,16 @@ public:
     /// determine if the log tag code indicates a cache HIT
     bool isTcpHit() const;
 
-    /// error states terminating the transaction
-    struct Errors {
-        Errors() : timedout(false), aborted(false) {}
+    /// Things that may happen to a transaction while it is being
+    /// processed according to its LOG_* category. Logged as _SUFFIX(es).
+    /// Unlike LOG_* categories, these flags may not be mutually exclusive.
+    class Errors {
+    public:
+        Errors() : ignored(false), timedout(false), aborted(false) {}
 
-        bool timedout; ///< tag: TIMEDOUT - terminated due to a lifetime or I/O timeout
-        bool aborted;  ///< tag: ABORTED  - other abnormal termination (e.g., I/O error)
+        bool ignored; ///< _IGNORED: the response was not used for anything
+        bool timedout; ///< _TIMEDOUT: terminated due to a lifetime or I/O timeout
+        bool aborted;  ///< _ABORTED: other abnormal termination (e.g., I/O error)
     } err;
 
 private:

diff --git a/src/client_side_reply.cc b/src/client_side_reply.cc
index c6edf1042223185943ce6c69b6d69e124c3628a4..34498080fdf9eb4c64c1df047813f664d05dab3b 100644 (file)
--- a/src/client_side_reply.cc
+++ b/src/client_side_reply.cc
@@ -407,7 +407,7 @@ clientReplyContext::handleIMSReply(StoreIOBuffer result)
     if (deleting)
         return;
 
-    debugs(88, 3, "handleIMSReply: " << http->storeEntry()->url() << ", " << (long unsigned) result.length << " bytes" );
+    debugs(88, 3, http->storeEntry()->url() << ", " << (long unsigned) result.length << " bytes");
 
     if (http->storeEntry() == NULL)
         return;
@@ -422,7 +422,7 @@ clientReplyContext::handleIMSReply(StoreIOBuffer result)
 
     // request to origin was aborted
     if (EBIT_TEST(http->storeEntry()->flags, ENTRY_ABORTED)) {
-        debugs(88, 3, "handleIMSReply: request to origin aborted '" << http->storeEntry()->url() << "', sending old entry to client" );
+        debugs(88, 3, "request to origin aborted '" << http->storeEntry()->url() << "', sending old entry to client");
         http->logType = LOG_TCP_REFRESH_FAIL_OLD;
         sendClientOldEntry();
     }
@@ -441,11 +441,11 @@ clientReplyContext::handleIMSReply(StoreIOBuffer result)
 
         if (http->request->flags.ims && !old_entry->modifiedSince(http->request->ims, http->request->imslen)) {
             // forward the 304 from origin
-            debugs(88, 3, "handleIMSReply: origin replied 304, revalidating existing entry and forwarding 304 to client");
+            debugs(88, 3, "origin replied 304, revalidating existing entry and forwarding 304 to client");
             sendClientUpstreamResponse();
         } else {
             // send existing entry, it's still valid
-            debugs(88, 3, "handleIMSReply: origin replied 304, revalidating existing entry and sending " <<
+            debugs(88, 3, "origin replied 304, revalidating existing entry and sending " <<
                    old_rep->sline.status() << " to client");
             sendClientOldEntry();
         }
@@ -453,26 +453,37 @@ clientReplyContext::handleIMSReply(StoreIOBuffer result)
 
     // origin replied with a non-error code
     else if (status > Http::scNone && status < Http::scInternalServerError) {
-        // forward response from origin
-        http->logType = LOG_TCP_REFRESH_MODIFIED;
-        debugs(88, 3, "handleIMSReply: origin replied " << status << ", replacing existing entry and forwarding to client");
+        const HttpReply *new_rep = http->storeEntry()->getReply();
+        // RFC 7234 section 4: a cache MUST use the most recent response
+        // (as determined by the Date header field)
+        if (new_rep->olderThan(old_rep)) {
+            http->logType.err.ignored = true;
+            debugs(88, 3, "origin replied " << status <<
+                   " but with an older date header, sending old entry (" <<
+                   old_rep->sline.status() << ") to client");
+            sendClientOldEntry();
+        } else {
+            http->logType = LOG_TCP_REFRESH_MODIFIED;
+            debugs(88, 3, "origin replied " << status <<
+                   ", replacing existing entry and forwarding to client");
 
-        if (collapsedRevalidation)
-            http->storeEntry()->clearPublicKeyScope();
+            if (collapsedRevalidation)
+                http->storeEntry()->clearPublicKeyScope();
 
-        sendClientUpstreamResponse();
+            sendClientUpstreamResponse();
+        }
     }
 
     // origin replied with an error
     else if (http->request->flags.failOnValidationError) {
         http->logType = LOG_TCP_REFRESH_FAIL_ERR;
-        debugs(88, 3, "handleIMSReply: origin replied with error " << status <<
+        debugs(88, 3, "origin replied with error " << status <<
                ", forwarding to client due to fail_on_validation_err");
         sendClientUpstreamResponse();
     } else {
         // ignore and let client have old entry
         http->logType = LOG_TCP_REFRESH_FAIL_OLD;
-        debugs(88, 3, "handleIMSReply: origin replied with error " <<
+        debugs(88, 3, "origin replied with error " <<
                status << ", sending old entry (" << old_rep->sline.status() << ") to client");
         sendClientOldEntry();
     }

diff --git a/src/http.cc b/src/http.cc
index 847e47be1027cf1b4df091b3ed3b5c24cc2beecb..4f98545609d3d3a2753818f9370058eabd082ce5 100644 (file)
--- a/src/http.cc
+++ b/src/http.cc
@@ -90,7 +90,8 @@ HttpStateData::HttpStateData(FwdState *theFwdState) :
     lastChunk(0),
     httpChunkDecoder(NULL),
     payloadSeen(0),
-    payloadTruncated(0)
+    payloadTruncated(0),
+    sawDateGoBack(false)
 {
     debugs(11,5,HERE << "HttpStateData " << this << " created");
     ignoreCacheControl = false;
@@ -168,6 +169,14 @@ HttpStateData::httpTimeout(const CommTimeoutCbParams &)
     mustStop("HttpStateData::httpTimeout");
 }
 
+static StoreEntry *
+findPreviouslyCachedEntry(StoreEntry *newEntry) {
+    assert(newEntry->mem_obj);
+    return newEntry->mem_obj->request ?
+           storeGetPublicByRequest(newEntry->mem_obj->request) :
+           storeGetPublic(newEntry->mem_obj->storeId(), newEntry->mem_obj->method);
+}
+
 /// Remove an existing public store entry if the incoming response (to be
 /// stored in a currently private entry) is going to invalidate it.
 static void
@@ -175,7 +184,6 @@ httpMaybeRemovePublic(StoreEntry * e, Http::StatusCode status)
 {
     int remove = 0;
     int forbidden = 0;
-    StoreEntry *pe;
 
     // If the incoming response already goes into a public entry, then there is
     // nothing to remove. This protects ready-for-collapsing entries as well.
@@ -234,12 +242,7 @@ httpMaybeRemovePublic(StoreEntry * e, Http::StatusCode status)
     if (!remove && !forbidden)
         return;
 
-    assert(e->mem_obj);
-
-    if (e->mem_obj->request)
-        pe = storeGetPublicByRequest(e->mem_obj->request);
-    else
-        pe = storeGetPublic(e->mem_obj->storeId(), e->mem_obj->method);
+    StoreEntry *pe = findPreviouslyCachedEntry(e);
 
     if (pe != NULL) {
         assert(e != pe);
@@ -330,6 +333,13 @@ HttpStateData::cacheableReply()
         return 0;
     }
 
+    // RFC 7234 section 4: a cache MUST use the most recent response
+    // (as determined by the Date header field)
+    if (sawDateGoBack) {
+        debugs(22, 3, "NO because " << *entry << " has an older date header.");
+        return 0;
+    }
+
     // Check for Surrogate/1.0 protocol conditions
     // NP: reverse-proxy traffic our parent server has instructed us never to cache
     if (surrogateNoStore) {
@@ -916,7 +926,10 @@ HttpStateData::haveParsedReplyHeaders()
     /* Check if object is cacheable or not based on reply code */
     debugs(11, 3, "HTTP CODE: " << rep->sline.status());
 
-    if (neighbors_do_private_keys)
+    if (const StoreEntry *oldEntry = findPreviouslyCachedEntry(entry))
+        sawDateGoBack = rep->olderThan(oldEntry->getReply());
+
+    if (neighbors_do_private_keys && !sawDateGoBack)
         httpMaybeRemovePublic(entry, rep->sline.status());
 
     bool varyFailure = false;

diff --git a/src/http.h b/src/http.h
index c115e08a59f3b3c0087145060fa6ad0b330ff1df..db86ea9519e1227b534a0c38c3780512c6798c54 100644 (file)
--- a/src/http.h
+++ b/src/http.h
@@ -129,6 +129,10 @@ private:
     int64_t payloadSeen;
     /// positive when we read more than we wanted
     int64_t payloadTruncated;
+
+    /// Whether we received a Date header older than that of a matching
+    /// cached response.
+    bool sawDateGoBack;
 };
 
 int httpCachable(const HttpRequestMethod&);