This is an automated email from the ASF dual-hosted git repository.
bcall pushed a commit to branch 9.2.x
in repository https://gitbox.apache.org/repos/asf/trafficserver.git
The following commit(s) were added to refs/heads/9.2.x by this push:
new 75328aa8f4 header_freq: Fix msg lock issues (#10988)
75328aa8f4 is described below
commit 75328aa8f47a744c0bb3c4d43795736fa0b11ba4
Author: Chris McFarlen <ch...@mcfarlen.us>
AuthorDate: Mon Jan 29 16:39:40 2024 -0600
header_freq: Fix msg lock issues (#10988)
* header_freq: Fix msg lock issues
* fix docs
Co-authored-by: Chris McFarlen <cmcfar...@apple.com>
(cherry picked from commit 78ccc61c9c803c39b3a874588fe2b3b2d52e9a0d)
---
doc/admin-guide/plugins/header_freq.en.rst | 20 ++-
plugins/experimental/header_freq/header_freq.cc | 186 +++++++++++++++++-------
2 files changed, 144 insertions(+), 62 deletions(-)
diff --git a/doc/admin-guide/plugins/header_freq.en.rst
b/doc/admin-guide/plugins/header_freq.en.rst
index a5214b5ef2..398b7357cf 100644
--- a/doc/admin-guide/plugins/header_freq.en.rst
+++ b/doc/admin-guide/plugins/header_freq.en.rst
@@ -20,21 +20,29 @@ Header Frequency Plugin
specific language governing permissions and limitations
under the License.
-The Header Frequency plugin keeps track of the number of times headers
-have been seen in transactions. Two separate counteres are kept for
-the origin and the client. This information is accessible via ::
+The Header Frequency plugin keeps track of the number of times headers have
been
+seen in transactions. Two separate counteres are kept for the origin and the
+client. This information is accessible via the ``log`` plugin message. By
+default the data is sent to traffic.out but it can alternatively be appended to
+an arbitrary file. The following logs the stats to ``traffic.out``::
traffic_ctl plugin msg header_freq log
+The following appends the stats to ``/tmp/log.txt``. Note that this file must
be
+writeable by the traffic_server process's user::
+
+ traffic_ctl plugin msg header_freq log:/tmp/log.txt
+
+
Installation
------------
-This plugin is only built if the configure option ::
+Since Header Frequency plugin is an expiremental plugin, traffic_server must
be configured
+to build experimental plugins in order to use it::
--enable-experimental-plugins
-is given at build time.
-Add the following line to :file:`plugin.config`::
+Once built, add the following line to :file:`plugin.config` and restart
traffic_server to use it::
header_freq.so
diff --git a/plugins/experimental/header_freq/header_freq.cc
b/plugins/experimental/header_freq/header_freq.cc
index e498b3769f..3422d097f0 100644
--- a/plugins/experimental/header_freq/header_freq.cc
+++ b/plugins/experimental/header_freq/header_freq.cc
@@ -22,12 +22,19 @@
limitations under the License.
*/
-#include <iostream>
-#include <map>
-#include <fstream>
+#include <algorithm>
+#include <atomic>
#include <cstdlib>
#include <cstring>
+#include <fstream>
+#include <iostream>
+#include <mutex>
+#include <shared_mutex>
#include <string>
+#include <unordered_map>
+#include <vector>
+
+#include "ts/apidefs.h"
#include <ts/ts.h>
namespace
@@ -43,31 +50,47 @@ const char DEBUG_TAG_INIT[] = "header_freq.init";
// debug messages in continuation callbacks
const char DEBUG_TAG_HOOK[] = "header_freq.hook";
-// maps from header name to # of times encountered
-std::map<std::string, unsigned int> client_freq;
-std::map<std::string, unsigned int> origin_freq;
+// A map from header name to the number of times the header was encountered.
+using CountMap_t = std::unordered_map<std::string, std::atomic<unsigned int>>;
+CountMap_t client_freq;
+CountMap_t origin_freq;
+std::shared_mutex map_mutex;
+
+// A vector for when we want to sort the map.
+using CountVector_t = std::vector<std::pair<std::string, unsigned int>>;
// for traffic_ctl, name is a convenient identifier
const char *ctl_tag = PLUGIN_NAME;
const char CONTROL_MSG_LOG[] = "log"; // log all data
const size_t CONTROL_MSG_LOG_LEN = sizeof(CONTROL_MSG_LOG) - 1;
+void
+Log_Sorted_Map(CountMap_t const &map, std::ostream &ss)
+{
+ CountVector_t sorted_vector;
+ {
+ std::shared_lock<std::shared_mutex> lock(map_mutex);
+ sorted_vector = CountVector_t(map.begin(), map.end());
+ }
+ std::sort(sorted_vector.begin(), sorted_vector.end(), [](const auto &a,
const auto &b) -> bool { return a.second > b.second; });
+
+ for (auto const &[header_name, count] : sorted_vector) {
+ ss << header_name << ": " << count << std::endl;
+ }
+}
+
void
Log_Data(std::ostream &ss)
{
ss << std::endl << std::string(100, '+') << std::endl;
ss << "CLIENT HEADERS" << std::endl;
- for (auto &elem : client_freq) {
- ss << elem.first << ": " << elem.second << std::endl;
- }
+ Log_Sorted_Map(client_freq, ss);
ss << std::endl;
ss << "ORIGIN HEADERS" << std::endl;
- for (auto &elem : origin_freq) {
- ss << elem.first << ": " << elem.second << std::endl;
- }
+ Log_Sorted_Map(origin_freq, ss);
ss << std::string(100, '+') << std::endl;
}
@@ -80,6 +103,11 @@ int
CB_Command_Log(TSCont contp, TSEvent event, void *edata)
{
std::string *command = static_cast<std::string *>(TSContDataGet(contp));
+ if (nullptr == command) {
+ TSError("[%s] Could not get the message argument from the log handler.",
PLUGIN_NAME);
+ return TS_ERROR;
+ }
+
std::string::size_type colon_idx;
if (std::string::npos != (colon_idx = command->find(':'))) {
@@ -94,12 +122,13 @@ CB_Command_Log(TSCont contp, TSEvent event, void *edata)
if (out.is_open()) {
Log_Data(out);
} else {
- TSError("[%s] Failed to open file '%s' for logging", PLUGIN_NAME,
path.c_str());
+ TSError("[%s] Failed to open file '%s' for logging: %s", PLUGIN_NAME,
path.c_str(), strerror(errno));
}
} else {
TSError("[%s] Invalid (zero length) file name for logging", PLUGIN_NAME);
}
} else {
+ // No filename provided, log to stdout (traffic.out).
Log_Data(std::cout);
}
@@ -114,7 +143,7 @@ CB_Command_Log(TSCont contp, TSEvent event, void *edata)
* against existing entries is case-insensitive.
*/
static void
-count_all_headers(TSMBuffer &bufp, TSMLoc &hdr_loc, std::map<std::string,
unsigned int> &map)
+count_all_headers(TSMBuffer &bufp, TSMLoc &hdr_loc, CountMap_t &map)
{
TSMLoc hdr, next_hdr;
hdr = TSMimeHdrFieldGet(bufp, hdr_loc, 0);
@@ -132,7 +161,20 @@ count_all_headers(TSMBuffer &bufp, TSMLoc &hdr_loc,
std::map<std::string, unsign
c = tolower(c);
}
- ++map[str];
+ { // For lock scoping.
+ std::shared_lock<std::shared_mutex> reader_lock{map_mutex};
+ if (map.find(str) == map.end()) {
+ // Upgrade the lock to be exclusive.
+ reader_lock.unlock();
+ std::unique_lock<std::shared_mutex> ulock{map_mutex};
+ // There's a potential race condition here such that another thread may
+ // have inserted the key while we were upgrading the lock. Regardless,
+ // incrementing the value here always does the right thing.
+ ++map[str];
+ } else {
+ ++map[str];
+ }
+ }
next_hdr = TSMimeHdrFieldNext(bufp, hdr_loc, hdr);
TSHandleMLocRelease(bufp, hdr_loc, hdr);
@@ -142,47 +184,73 @@ count_all_headers(TSMBuffer &bufp, TSMLoc &hdr_loc,
std::map<std::string, unsign
TSHandleMLocRelease(bufp, TS_NULL_MLOC, hdr_loc);
}
-/**
- * Continuation callback. Invoked to count headers on READ_REQUEST_HDR and
- * SEND_RESPONSE_HDR hooks and to log through traffic_ctl's LIFECYCLE_MSG.
+/** Handle common logic between the request and response headers.
+ * @param[in] txnp The transaction pointer for this HTTP message.
+ * @param[in] event The event that triggered this callback.
+ * @param[out] freq_map The map to update with the header counts.
+ * @return TS_SUCCESS if the event was handled successfully, TS_ERROR
otherwise.
*/
int
-handle_hook(TSCont contp, TSEvent event, void *edata)
+handle_header_event(TSHttpTxn txnp, TSEvent event, CountMap_t &freq_map)
{
- TSHttpTxn txnp;
TSMBuffer bufp;
TSMLoc hdr_loc;
- int ret_val = 0;
+ TSReturnCode ret;
+
+ char const *message_type = nullptr;
+ if (event == TS_EVENT_HTTP_READ_REQUEST_HDR) {
+ message_type = "request";
+ ret = TSHttpTxnClientReqGet(txnp, &bufp, &hdr_loc);
+ } else { // TS_EVENT_HTTP_SEND_RESPONSE_HDR
+ message_type = "response";
+ ret = TSHttpTxnClientRespGet(txnp, &bufp, &hdr_loc);
+ }
+
+ if (ret != TS_SUCCESS) {
+ TSError("[%s] could not get %s headers", PLUGIN_NAME, message_type);
+ TSHttpTxnReenable(txnp, TS_EVENT_HTTP_ERROR);
+ return TS_ERROR;
+ }
+
+ count_all_headers(bufp, hdr_loc, freq_map);
+ TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE);
+ return TS_SUCCESS;
+}
+
+/** Continuation callback. Invoked to count headers on READ_REQUEST_HDR and
+ * SEND_RESPONSE_HDR hooks.
+ */
+int
+header_handle_hook(TSCont contp, TSEvent event, void *edata)
+{
+ TSHttpTxn txnp = reinterpret_cast<TSHttpTxn>(edata);
+ int ret_val = TS_SUCCESS;
switch (event) {
case TS_EVENT_HTTP_READ_REQUEST_HDR: // count client headers
- {
TSDebug(DEBUG_TAG_HOOK, "event TS_EVENT_HTTP_READ_REQUEST_HDR");
- txnp = reinterpret_cast<TSHttpTxn>(edata);
- // get the client request so we can loop through the headers
- if (TSHttpTxnClientReqGet(txnp, &bufp, &hdr_loc) != TS_SUCCESS) {
- TSError("[%s] could not get request headers", PLUGIN_NAME);
- TSHttpTxnReenable(txnp, TS_EVENT_HTTP_ERROR);
- ret_val = -1;
- break;
- }
- count_all_headers(bufp, hdr_loc, client_freq);
- TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE);
- } break;
+ ret_val = handle_header_event(txnp, event, client_freq);
+ break;
case TS_EVENT_HTTP_SEND_RESPONSE_HDR: // count origin headers
- {
TSDebug(DEBUG_TAG_HOOK, "event TS_EVENT_HTTP_SEND_RESPONSE_HDR");
- // get the response so we can loop through the headers
- txnp = reinterpret_cast<TSHttpTxn>(edata);
- if (TSHttpTxnClientRespGet(txnp, &bufp, &hdr_loc) != TS_SUCCESS) {
- TSError("[%s] could not get response headers", PLUGIN_NAME);
- TSHttpTxnReenable(txnp, TS_EVENT_HTTP_ERROR);
- ret_val = -2;
- break;
- }
- count_all_headers(bufp, hdr_loc, origin_freq);
- TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE);
- } break;
+ ret_val = handle_header_event(txnp, event, origin_freq);
+ break;
+ default:
+ TSError("[%s] unexpected event in header handler: %d", PLUGIN_NAME, event);
+ break;
+ }
+
+ return ret_val;
+}
+
+/**
+ * Continuation callback. Invoked to handler the LIFE_CYCLE_MSG event to log
+ * header stats.
+ */
+int
+msg_handle_hook(TSCont contp, TSEvent event, void *edata)
+{
+ switch (event) {
case TS_EVENT_LIFECYCLE_MSG: // Handle external command
{
TSPluginMsg *msgp = static_cast<TSPluginMsg *>(edata);
@@ -203,15 +271,15 @@ handle_hook(TSCont contp, TSEvent event, void *edata)
}
}
} break;
- // do nothing in any of the other states
default:
+ TSError("[%s] unexpected event in message handler: %d", PLUGIN_NAME,
event);
break;
}
- return ret_val;
+ return TS_SUCCESS;
}
-} // namespace
+} // anonymous namespace
/// Registration entry point for plugin.
void
@@ -225,15 +293,21 @@ TSPluginInit(int argc, const char *argv[])
TSError("[%s](%s) Plugin registration failed. \n", PLUGIN_NAME,
__FUNCTION__);
}
- TSCont contp = TSContCreate(handle_hook, TSMutexCreate());
- if (contp == nullptr) {
+ TSCont header_contp = TSContCreate(header_handle_hook, nullptr);
+ if (header_contp == nullptr) {
// Continuation initialization failed. Unrecoverable, report and exit.
- TSError("[%s](%s) could not create continuation", PLUGIN_NAME,
__FUNCTION__);
+ TSError("[%s](%s) could not create the header handler continuation",
PLUGIN_NAME, __FUNCTION__);
+ abort();
+ }
+ // Continuation initialization succeeded
+ TSHttpHookAdd(TS_HTTP_READ_REQUEST_HDR_HOOK, header_contp);
+ TSHttpHookAdd(TS_HTTP_SEND_RESPONSE_HDR_HOOK, header_contp);
+
+ TSCont msg_contp = TSContCreate(msg_handle_hook, nullptr);
+ if (msg_contp == nullptr) {
+ // Continuation initialization failed. Unrecoverable, report and exit.
+ TSError("[%s](%s) could not create the message handler continuation",
PLUGIN_NAME, __FUNCTION__);
abort();
- } else {
- // Continuation initialization succeeded
- TSHttpHookAdd(TS_HTTP_READ_REQUEST_HDR_HOOK, contp);
- TSHttpHookAdd(TS_HTTP_SEND_RESPONSE_HDR_HOOK, contp);
- TSLifecycleHookAdd(TS_LIFECYCLE_MSG_HOOK, contp);
}
+ TSLifecycleHookAdd(TS_LIFECYCLE_MSG_HOOK, msg_contp);
}
