Fix Cache Result Code of negative revalidation cases

src/proxy/http/HttpTransact.cc

@@ -4349,6 +4349,9 @@ HttpTransact::handle_cache_operation_on_forward_server_response(State *s)
         base_response->set_expires(exp_time);
 
         SET_VIA_STRING(VIA_CACHE_FILL_ACTION, VIA_CACHE_UPDATED);
+        SET_VIA_STRING(VIA_CACHE_RESULT, VIA_IN_CACHE_STALE);
+        // change VIA_SERVER_RESULT to ERROR because this status hit the negative_revalidating_list
+        SET_VIA_STRING(VIA_SERVER_RESULT, VIA_SERVER_ERROR);
         Metrics::Counter::increment(http_rsb.cache_updates);
 
         // unset Cache-control: "need-revalidate-once" (if it's set)

src/proxy/http/HttpTransactHeaders.cc

@@ -39,6 +39,7 @@
 #include "proxy/hdrs/HTTP.h"
 
 #include "iocore/utils/Machine.h"
+#include "tsutil/DbgCtl.h"
 
 using namespace std::literals;
 
@@ -423,6 +424,8 @@ HttpTransactHeaders::downgrade_request(bool *origin_server_keep_alive, HTTPHdr *
 void
 HttpTransactHeaders::generate_and_set_squid_codes(HTTPHdr *header, char *via_string, HttpTransact::SquidLogInfo *squid_codes)
 {
+  Dbg(dbg_ctl_http_transact_headers, "via_string=%s", via_string);
+
   SquidLogCode       log_code      = SquidLogCode::EMPTY;
   SquidHierarchyCode hier_code     = SquidHierarchyCode::EMPTY;
   SquidHitMissCode   hit_miss_code = SQUID_HIT_RESERVED;
@@ -479,6 +482,8 @@ HttpTransactHeaders::generate_and_set_squid_codes(HTTPHdr *header, char *via_str
       } else {
         if (via_string[VIA_CACHE_RESULT] == VIA_IN_CACHE_STALE && via_string[VIA_SERVER_RESULT] == VIA_SERVER_NOT_MODIFIED) {
           log_code = SquidLogCode::TCP_REFRESH_HIT;
+        } else if (via_string[VIA_CACHE_RESULT] == VIA_IN_CACHE_STALE && via_string[VIA_SERVER_RESULT] == VIA_SERVER_ERROR) {
+          log_code = SquidLogCode::TCP_REF_FAIL_HIT;
         } else {
           log_code = SquidLogCode::TCP_IMS_MISS;
         }

tests/gold_tests/autest-site/ats_replay.test.ext

@@ -47,6 +47,11 @@ def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Opti
     for parent_line in parent_config:
         ts.Disk.parent_config.AddLine(parent_line)
 
+    # Configure logging.yaml if specified.
+    logging_yaml = ats_config.get('logging_yaml')
+    if logging_yaml != None:
+        ts.Disk.logging_yaml.AddLines(yaml.dump(logging_yaml).split('\n'))
+
     remap_config = ats_config.get('remap_config', [])
     for remap_entry in remap_config:
         if isinstance(remap_entry, str):
@@ -113,6 +118,11 @@ def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Opti
             gold_file = diags_log['gold_file']
             ts.Disk.diags_log.Content += gold_file
 
+        # access_log validation.
+        access_log = log_validation.get('access_log', {})
+        if 'gold_file' in access_log:
+            obj.Disk.File(os.path.join(ts.Variables.LOGDIR, access_log['filename']), exists=True, content=access_log['gold_file'])
+
     return ts
 
 

tests/gold_tests/cache/gold/negative-revalidating-enabled-access.gold

@@ -0,0 +1,15 @@
+11 TCP_MISS 200 200
+31 TCP_MISS 200 200
+12 TCP_MEM_HIT 200 000
+42 TCP_IMS_HIT 304 000
+32 TCP_MEM_HIT 200 000
+13 TCP_REFRESH_FAIL_HIT 200 503
+43 TCP_REFRESH_FAIL_HIT 304 503
+33 TCP_REFRESH_FAIL_HIT 200 503
+34 TCP_REFRESH_FAIL_HIT 200 503
+14 TCP_REFRESH_MISS 503 503
+35 TCP_REFRESH_MISS 503 503
+21 TCP_MISS 200 200
+22 TCP_MEM_HIT 200 000
+23 TCP_REFRESH_FAIL_HIT 200 503
+``

tests/gold_tests/cache/replay/negative-revalidating-enabled.replay.yaml

@@ -53,6 +53,22 @@ autest:
       - from: "http://example.com/"
         to: "http://backend.example.com:{SERVER_HTTP_PORT}/"
 
+    logging_yaml:
+      logging:
+        formats:
+          - name: access
+            format: '%<{uuid}cqh> %<crc> %<pssc> %<sssc>'
+
+        logs:
+          - filename: access
+            format: access
+            mode: ascii
+
+    log_validation:
+      access_log:
+        filename: access.log
+        gold_file: gold/negative-revalidating-enabled-access.gold
+
 sessions:
 - transactions:
 
@@ -77,6 +93,7 @@ sessions:
         fields:
         - [ Content-Length, 32 ]
         - [ Cache-Control, max-age=2 ]
+        - [ ETag, C0FFEE ]
 
     proxy-response:
       status: 200
@@ -130,6 +147,30 @@ sessions:
     proxy-response:
       status: 200
 
+  # Verify we serve the 304 Not Modified out of the cache with INM request
+  - client-request:
+      method: "GET"
+      version: "1.1"
+      scheme: "http"
+      url: /path/reques_item
+      headers:
+        fields:
+        - [ Host, example.com ]
+        - [ uuid, 42 ]
+        - [ If-None-Match, C0FFEE ]
+
+    # This should not reach the origin server.
+    server-response:
+      status: 503
+      reason: "Service Unavailable"
+      headers:
+        fields:
+        - [ Content-Length, 32 ]
+
+    # Again, we should serve this out of the cache.
+    proxy-response:
+      status: 304
+
   # Verify zero-length is also served from cache when fresh.
   - client-request:
       method: "GET"
@@ -180,6 +221,30 @@ sessions:
     proxy-response:
       status: 200
 
+  # Verify that we serve the 304 Not Modified out of the cache with INM request
+  - client-request:
+      method: "GET"
+      version: "1.1"
+      scheme: "http"
+      url: /path/reques_item
+      headers:
+        fields:
+        - [ Host, example.com ]
+        - [ uuid, 43 ]
+        - [ If-None-Match, C0FFEE ]
+
+    # This should not reach the origin server.
+    server-response:
+      status: 503
+      reason: "Service Unavailable"
+      headers:
+        fields:
+        - [ Content-Length, 32 ]
+
+    # Again, we should serve this out of the cache.
+    proxy-response:
+      status: 304
+
   # Test zero-length while stale - first request (regression test for issue #6649).
   - client-request:
       method: "GET"