diff --git a/src/proxy/http/HttpTransact.cc b/src/proxy/http/HttpTransact.cc index aba3e30b7e5..8eb181da214 100644 --- a/src/proxy/http/HttpTransact.cc +++ b/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) diff --git a/src/proxy/http/HttpTransactHeaders.cc b/src/proxy/http/HttpTransactHeaders.cc index a7ecee2eb32..11e00c1bc18 100644 --- a/src/proxy/http/HttpTransactHeaders.cc +++ b/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; } diff --git a/tests/gold_tests/autest-site/ats_replay.test.ext b/tests/gold_tests/autest-site/ats_replay.test.ext index 63ee6c217f5..75bd1306d54 100644 --- a/tests/gold_tests/autest-site/ats_replay.test.ext +++ b/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 diff --git a/tests/gold_tests/cache/gold/negative-revalidating-enabled-access.gold b/tests/gold_tests/cache/gold/negative-revalidating-enabled-access.gold new file mode 100644 index 00000000000..b7b5e08abce --- /dev/null +++ b/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 +`` diff --git a/tests/gold_tests/cache/replay/negative-revalidating-enabled.replay.yaml b/tests/gold_tests/cache/replay/negative-revalidating-enabled.replay.yaml index 607c3816d34..fdf7fca6fc6 100644 --- a/tests/gold_tests/cache/replay/negative-revalidating-enabled.replay.yaml +++ b/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> % % %' + + 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"