You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by GitBox <gi...@apache.org> on 2021/12/02 20:24:31 UTC
[GitHub] [trafficserver] bneradt edited a comment on issue #8539: CACHE_LOOKUP_HIT_FRESH status for POST request is not good
bneradt edited a comment on issue #8539:
URL: https://github.com/apache/trafficserver/issues/8539#issuecomment-984973130
I've created and added the following plugin to the cache-request-method.test.py test. It reproduces the issue by printing the cache status which it sees:
```/**
@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 <ts/ts.h> // for debug
#include <cstdlib> // for abort
#include <cinttypes> // for PRId64
#include <string_view>
#include <unordered_map>
namespace
{
constexpr char const *PLUGIN_NAME = "print_cache_status";
std::unordered_map<int, std::string_view> 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<TSHttpTxn>(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);
}
TSDebug(PLUGIN_NAME, "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);
}
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);
}
}
```
The test is updated with:
```
$ git diff master -- tests/gold_tests/cache/cache-request-method.test.py
diff --git a/tests/gold_tests/cache/cache-request-method.test.py b/tests/gold_tests/cache/cache-request-method.test.py
index 5715e812a..d21dec035 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 @@ Verify correct caching behavior with respect to request method.
# 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,13 @@ Verify correct caching behavior with respect to request method.
# 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)
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
@@ -46,11 +50,13 @@ tr.AddVerifierClientProcess("client0", replay_file, http_ports=[ts.Variables.por
# 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)
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,
})
```
Running the test gives this output:
```
$ grep print_cache_status /tmp/sbcr/cache-request-method/_output/cache-request-method-ts/stream.all.txt
[Dec 2 19:55:46.134] traffic_server DIAG: (print_cache_status) initializing plugin
[Dec 2 19:55:46.173] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_MISS
[Dec 2 19:55:46.287] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH
[Dec 2 19:55:46.296] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH
[Dec 2 19:55:46.410] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_MISS
[Dec 2 19:55:46.526] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH
[Dec 2 19:55:46.534] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH
[Dec 2 19:55:46.646] [ET_NET 3] DIAG: (print_cache_status) Cache lookup status: TS_CACHE_LOOKUP_HIT_FRESH
```
The test does the following:
1. GET for a resource. Should be a miss and it is (good).
2. Repeats the GET. Should be a hit and it is (good).
3. Does a POST for the resource. This results in a hit, which this ticket records as confusing to the plugin because the resource is actually rejected because the methods don't line up. This, therefore, is reproducing the behavior this ticket records.
4. The 200 OK to the previous POST invalidates the resource. The GET is therefore a miss, which is good.
5. A GET is repeated, which replies out of cache. This should be a hit and it is (good).
6. A POST is repeated, which again replies with a HIT. This also reproduces what is described in this ticket.
7. Unlike before, the server replies to the POST with an error response. Thus the original resource is not invalidated. A GET is made for the resource which receives a hit, which is good.
Thus requests 3 and 6 reproduce this problem described in this ticket.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org