diff --git a/proxy/http/HttpTransact.cc b/proxy/http/HttpTransact.cc index ac8a1df1406..7a46aa4f40f 100644 --- a/proxy/http/HttpTransact.cc +++ b/proxy/http/HttpTransact.cc @@ -2757,12 +2757,13 @@ HttpTransact::need_to_revalidate(State *s) needs_revalidate = false; } - bool send_revalidate = ((needs_authenticate == true) || (needs_revalidate == true) || (is_cache_response_returnable(s) == false)); + s->cache_hit_but_revalidate = + ((needs_authenticate == true) || (needs_revalidate == true) || (is_cache_response_returnable(s) == false)); if (needs_cache_auth == true) { - s->www_auth_content = send_revalidate ? CACHE_AUTH_STALE : CACHE_AUTH_FRESH; - send_revalidate = true; + s->www_auth_content = s->cache_hit_but_revalidate ? CACHE_AUTH_STALE : CACHE_AUTH_FRESH; + s->cache_hit_but_revalidate = true; } - return send_revalidate; + return s->cache_hit_but_revalidate; } /////////////////////////////////////////////////////////////////////////////// @@ -2881,21 +2882,21 @@ HttpTransact::HandleCacheOpenReadHit(State *s) // do we need to revalidate. in other words if the response // has to be authorized, is stale or can not be returned, do // a revalidate. - bool send_revalidate = (needs_authenticate || needs_revalidate || !response_returnable); + s->cache_hit_but_revalidate = (needs_authenticate || needs_revalidate || !response_returnable); if (needs_cache_auth == true) { SET_VIA_STRING(VIA_DETAIL_CACHE_LOOKUP, VIA_DETAIL_MISS_EXPIRED); - s->www_auth_content = send_revalidate ? CACHE_AUTH_STALE : CACHE_AUTH_FRESH; - send_revalidate = true; + s->www_auth_content = s->cache_hit_but_revalidate ? CACHE_AUTH_STALE : CACHE_AUTH_FRESH; + s->cache_hit_but_revalidate = true; } TxnDebug("http_trans", "CacheOpenRead --- needs_auth = %d", needs_authenticate); TxnDebug("http_trans", "CacheOpenRead --- needs_revalidate = %d", needs_revalidate); TxnDebug("http_trans", "CacheOpenRead --- response_returnable = %d", response_returnable); TxnDebug("http_trans", "CacheOpenRead --- needs_cache_auth = %d", needs_cache_auth); - TxnDebug("http_trans", "CacheOpenRead --- send_revalidate = %d", send_revalidate); + TxnDebug("http_trans", "CacheOpenRead --- send_revalidate = %d", s->cache_hit_but_revalidate); - if (send_revalidate) { + if (s->cache_hit_but_revalidate) { TxnDebug("http_trans", "CacheOpenRead --- HIT-STALE"); TxnDebug("http_seq", "[HttpTransact::HandleCacheOpenReadHit] " @@ -2997,7 +2998,8 @@ HttpTransact::HandleCacheOpenReadHit(State *s) // realistically, if we can not make this claim, then there // is no reason to cache anything. // - ink_assert((send_revalidate == true && server_up == false) || (send_revalidate == false && server_up == true)); + ink_assert((s->cache_hit_but_revalidate == true && server_up == false) || + (s->cache_hit_but_revalidate == false && server_up == true)); TxnDebug("http_trans", "CacheOpenRead --- HIT-FRESH"); TxnDebug("http_seq", "[HttpTransact::HandleCacheOpenReadHit] " diff --git a/proxy/http/HttpTransact.h b/proxy/http/HttpTransact.h index 2ec1e45af6a..ec4a9d78685 100644 --- a/proxy/http/HttpTransact.h +++ b/proxy/http/HttpTransact.h @@ -700,6 +700,13 @@ class HttpTransact ParentResult parent_result; CacheControlResult cache_control; CacheLookupResult_t cache_lookup_result = CACHE_LOOKUP_NONE; + /** There was a cache hit, but the cached resource cannot be used. + * + * This may happen because it is stale, it needs authentication, or the + * request method of the incoming request doesn't match that of the request + * corresponding to the cached resource. + */ + bool cache_hit_but_revalidate = false; StateMachineAction_t next_action = SM_ACTION_UNDEFINED; // out StateMachineAction_t api_next_action = SM_ACTION_UNDEFINED; // out diff --git a/src/traffic_server/InkAPI.cc b/src/traffic_server/InkAPI.cc index f43796cad4f..c9500972bf5 100644 --- a/src/traffic_server/InkAPI.cc +++ b/src/traffic_server/InkAPI.cc @@ -5429,7 +5429,11 @@ TSHttpTxnCacheLookupStatusGet(TSHttpTxn txnp, int *lookup_status) break; case HttpTransact::CACHE_LOOKUP_HIT_WARNING: case HttpTransact::CACHE_LOOKUP_HIT_FRESH: - *lookup_status = TS_CACHE_LOOKUP_HIT_FRESH; + if (sm->t_state.cache_hit_but_revalidate) { + *lookup_status = TS_CACHE_LOOKUP_MISS; + } else { + *lookup_status = TS_CACHE_LOOKUP_HIT_FRESH; + } break; case HttpTransact::CACHE_LOOKUP_SKIPPED: *lookup_status = TS_CACHE_LOOKUP_SKIPPED; diff --git a/tests/Makefile.am b/tests/Makefile.am index 391078815e5..81e7a1505e7 100644 --- a/tests/Makefile.am +++ b/tests/Makefile.am @@ -31,6 +31,7 @@ AM_LDFLAGS += $(TS_PLUGIN_LD_FLAGS) AM_LDFLAGS += -rpath $(abs_builddir) include gold_tests/bigobj/Makefile.inc +include gold_tests/cache/plugins/Makefile.inc include gold_tests/continuations/plugins/Makefile.inc include gold_tests/chunked_encoding/Makefile.inc include gold_tests/pluginTest/tsapi/Makefile.inc diff --git a/tests/gold_tests/cache/cache-request-method.test.py b/tests/gold_tests/cache/cache-request-method.test.py index 5715e812a14..2db75f82f6c 100644 --- a/tests/gold_tests/cache/cache-request-method.test.py +++ b/tests/gold_tests/cache/cache-request-method.test.py @@ -17,6 +17,8 @@ # See the License for the specific language governing permissions and # limitations under the License. +import os + Test.Summary = ''' Verify correct caching behavior with respect to request method. ''' @@ -24,11 +26,15 @@ # Test 0: Verify correct POST response handling when caching POST responses is # disabled. ts = Test.MakeATSProcess("ts") +Test.PrepareTestPlugin(os.path.join(Test.Variables.AtsBuildGoldTestsDir, + 'cache', 'plugins', '.libs', 'print_cache_status.so'), ts) +Test.Disk.File(os.path.join(ts.Variables.LOGDIR, 'print_cache_status.log'), + exists=True, content='gold/print_cache_status_cache_post_disabled.gold') replay_file = "replay/post_with_post_caching_disabled.replay.yaml" server = Test.MakeVerifierServerProcess("server0", replay_file) ts.Disk.records_config.update({ 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'http.*|cache.*', + 'proxy.config.diags.debug.tags': 'http|cache|print_cache_status', 'proxy.config.http.insert_age_in_response': 0, # Caching of POST responses is disabled by default. Verify default behavior @@ -43,14 +49,26 @@ tr.Processes.Default.StartBefore(ts) tr.AddVerifierClientProcess("client0", replay_file, http_ports=[ts.Variables.port]) +# Wait for log file to appear, then wait one extra second to make sure TS is done writing it. +test_run = Test.AddTestRun() +test_run.Processes.Default.Command = ( + os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + + os.path.join(ts.Variables.LOGDIR, 'print_cache_status.log') +) +test_run.Processes.Default.ReturnCode = 0 + # Test 1: Verify correct POST response handling when caching POST responses is # enabled. ts = Test.MakeATSProcess("ts-cache-post") +Test.PrepareTestPlugin(os.path.join(Test.Variables.AtsBuildGoldTestsDir, + 'cache', 'plugins', '.libs', 'print_cache_status.so'), ts) +Test.Disk.File(os.path.join(ts.Variables.LOGDIR, 'print_cache_status.log'), + exists=True, content='gold/print_cache_status_cache_post_enabled.gold') replay_file = "replay/post_with_post_caching_enabled.replay.yaml" server = Test.MakeVerifierServerProcess("server1", replay_file) ts.Disk.records_config.update({ 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'http.*|cache.*', + 'proxy.config.diags.debug.tags': 'http|cache|print_cache_status', 'proxy.config.http.insert_age_in_response': 0, 'proxy.config.http.cache.post_method': 1, }) @@ -61,3 +79,11 @@ tr.Processes.Default.StartBefore(server) tr.Processes.Default.StartBefore(ts) tr.AddVerifierClientProcess("client1", replay_file, http_ports=[ts.Variables.port]) + +# Wait for log file to appear, then wait one extra second to make sure TS is done writing it. +test_run = Test.AddTestRun() +test_run.Processes.Default.Command = ( + os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + + os.path.join(ts.Variables.LOGDIR, 'print_cache_status.log') +) +test_run.Processes.Default.ReturnCode = 0 diff --git a/tests/gold_tests/cache/gold/print_cache_status_cache_post_disabled.gold b/tests/gold_tests/cache/gold/print_cache_status_cache_post_disabled.gold new file mode 100644 index 00000000000..90e2e8d7d0f --- /dev/null +++ b/tests/gold_tests/cache/gold/print_cache_status_cache_post_disabled.gold @@ -0,0 +1,7 @@ +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH diff --git a/tests/gold_tests/cache/gold/print_cache_status_cache_post_enabled.gold b/tests/gold_tests/cache/gold/print_cache_status_cache_post_enabled.gold new file mode 100644 index 00000000000..f795b2951c6 --- /dev/null +++ b/tests/gold_tests/cache/gold/print_cache_status_cache_post_enabled.gold @@ -0,0 +1,10 @@ +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_MISS +`` Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH diff --git a/tests/gold_tests/cache/plugins/Makefile.inc b/tests/gold_tests/cache/plugins/Makefile.inc new file mode 100644 index 00000000000..1b0b7baf920 --- /dev/null +++ b/tests/gold_tests/cache/plugins/Makefile.inc @@ -0,0 +1,18 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +noinst_LTLIBRARIES += gold_tests/cache/plugins/print_cache_status.la +gold_tests_cache_plugins_print_cache_status_la_SOURCES = gold_tests/cache/plugins/print_cache_status.cc diff --git a/tests/gold_tests/cache/plugins/print_cache_status.cc b/tests/gold_tests/cache/plugins/print_cache_status.cc new file mode 100644 index 00000000000..531b6aa4c6c --- /dev/null +++ b/tests/gold_tests/cache/plugins/print_cache_status.cc @@ -0,0 +1,89 @@ +/** + @file + @brief A plugin that prints the cache lookup status. + + @section license License + + Licensed to the Apache Software Foundation (ASF) under one + or more contributor license agreements. See the NOTICE file + distributed with this work for additional information + regarding copyright ownership. The ASF licenses this file + to you under the Apache License, Version 2.0 (the + "License"); you may not use this file except in compliance + with the License. You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. +*/ +#include // for debug +#include // for abort +#include // for PRId64 +#include +#include + +namespace +{ +constexpr char const *PLUGIN_NAME = "print_cache_status"; +static TSTextLogObject pluginlog; + +std::unordered_map lookup_status_to_string = { + {TS_CACHE_LOOKUP_MISS, "TS_CACHE_LOOKUP_MISS"}, + {TS_CACHE_LOOKUP_HIT_STALE, "TS_CACHE_LOOKUP_HIT_STALE"}, + {TS_CACHE_LOOKUP_HIT_FRESH, "TS_CACHE_LOOKUP_HIT_FRESH"}, + {TS_CACHE_LOOKUP_SKIPPED, "TS_CACHE_LOOKUP_SKIPPED"}, +}; + +int +global_handler(TSCont continuation, TSEvent event, void *data) +{ + TSHttpTxn txnp = static_cast(data); + + switch (event) { + case TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE: { + int obj_status = 0; + if (TS_ERROR == TSHttpTxnCacheLookupStatusGet(txnp, &obj_status)) { + TSError("[%s] TSHttpTxnCacheLookupStatusGet failed", PLUGIN_NAME); + } + TSTextLogObjectWrite(pluginlog, "Cache lookup status: %s", lookup_status_to_string[obj_status].data()); + } break; + + default: + TSError("[%s] Unexpected event: %d", PLUGIN_NAME, event); + return 0; + } + + TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE); + + return 0; +} +} // anonymous namespace + +void +TSPluginInit(int argc, const char *argv[]) +{ + TSDebug(PLUGIN_NAME, "initializing plugin"); + + TSPluginRegistrationInfo info; + + info.plugin_name = PLUGIN_NAME; + info.vendor_name = "Apache"; + info.support_email = "bneradt@apache.org"; + + if (TSPluginRegister(&info) != TS_SUCCESS) { + TSError("[%s] Plugin registration failed.", PLUGIN_NAME); + } + TSAssert(TS_SUCCESS == TSTextLogObjectCreate(PLUGIN_NAME, TS_LOG_MODE_ADD_TIMESTAMP, &pluginlog)); + + TSCont contp = TSContCreate(global_handler, TSMutexCreate()); + if (contp == nullptr) { + TSError("[%s] could not create continuation.", PLUGIN_NAME); + std::abort(); + } else { + TSHttpHookAdd(TS_HTTP_CACHE_LOOKUP_COMPLETE_HOOK, contp); + } +}