Repository: trafficserver Updated Branches: refs/heads/master c37ca5d03 -> ff45432a8
TS-2973: add x-milestones header to the xdebug plugin The X-Milestones header contains detailed information about how long the transaction took to traverse portions of the HTTP state machine. The timing information is obtained from the TSHttpTxnMilestoneGet API. Each milestone value is a fractional number of seconds since the beginning of the transaction. Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo Commit: http://git-wip-us.apache.org/repos/asf/trafficserver/commit/ff45432a Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/ff45432a Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/ff45432a Branch: refs/heads/master Commit: ff45432a88dbfc1b1354676a60f056f4830799e6 Parents: c37ca5d Author: James Peach <[email protected]> Authored: Sat Jul 5 17:27:18 2014 -0700 Committer: James Peach <[email protected]> Committed: Wed Jul 30 10:24:19 2014 -0700 ---------------------------------------------------------------------- CHANGES | 2 + doc/reference/plugins/xdebug.en.rst | 10 +++- plugins/experimental/xdebug/xdebug.cc | 77 ++++++++++++++++++++++++++++++ 3 files changed, 88 insertions(+), 1 deletion(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/trafficserver/blob/ff45432a/CHANGES ---------------------------------------------------------------------- diff --git a/CHANGES b/CHANGES index 45af9e8..405d2a7 100644 --- a/CHANGES +++ b/CHANGES @@ -1,6 +1,8 @@ -*- coding: utf-8 -*- Changes with Apache Traffic Server 5.1.0 + *) [TS-2973] Add milestones support to the xdebug plugin. + *) [TS-2957] Add new sslheaders plugin. *) [TS-2802] Add SNI support for origin server connections. http://git-wip-us.apache.org/repos/asf/trafficserver/blob/ff45432a/doc/reference/plugins/xdebug.en.rst ---------------------------------------------------------------------- diff --git a/doc/reference/plugins/xdebug.en.rst b/doc/reference/plugins/xdebug.en.rst index 5a4b340..003201f 100644 --- a/doc/reference/plugins/xdebug.en.rst +++ b/doc/reference/plugins/xdebug.en.rst @@ -42,6 +42,14 @@ Via to ``3`` for the request. X-Cache-Key - The ``X-Cache-Key`` contains the URL that identifies the HTTP object in the + The ``X-Cache-Key`` header contains the URL that identifies the HTTP object in the Traffic Server cache. This header is particularly useful if a custom cache key is being used. + +X-Milestones + The ``X-Milestones`` header contains detailed information about + how long the transaction took to traverse portions of the HTTP + state machine. The timing information is obtained from the + :c:func:`TSHttpTxnMilestoneGet` API. Each milestone value is a + fractional number of seconds since the beginning of the + transaction. http://git-wip-us.apache.org/repos/asf/trafficserver/blob/ff45432a/plugins/experimental/xdebug/xdebug.cc ---------------------------------------------------------------------- diff --git a/plugins/experimental/xdebug/xdebug.cc b/plugins/experimental/xdebug/xdebug.cc index 7f64dd9..883f5ca 100644 --- a/plugins/experimental/xdebug/xdebug.cc +++ b/plugins/experimental/xdebug/xdebug.cc @@ -18,12 +18,15 @@ #include <ts/ts.h> #include <stdlib.h> +#include <stdio.h> #include <strings.h> +#include "ink_defs.h" // The name of the debug request header. This should probably be configurable. #define X_DEBUG_HEADER "X-Debug" #define XHEADER_X_CACHE_KEY 0x0004u +#define XHEADER_X_MILESTONES 0x0008u static int XArgIndex = 0; static TSCont XInjectHeadersCont = NULL; @@ -95,6 +98,73 @@ done: TSfree(strval.ptr); } +static void +InjectMilestonesHeader(TSHttpTxn txn, TSMBuffer buffer, TSMLoc hdr) +{ + struct milestone { + TSMilestonesType mstype; + const char * msname; + }; + + // The set of milestones we can publish. Some milestones happen after + // this hook, so we skip those ... + static const milestone milestones[] = { + { TS_MILESTONE_UA_BEGIN, "UA-BEGIN" }, + { TS_MILESTONE_UA_READ_HEADER_DONE, "UA-READ-HEADER-DONE" }, + { TS_MILESTONE_UA_BEGIN_WRITE, "UA-BEGIN-WRITE" }, + { TS_MILESTONE_SERVER_FIRST_CONNECT, "SERVER-FIRST-CONNECT" }, + { TS_MILESTONE_SERVER_CONNECT, "SERVER-CONNECT" }, + { TS_MILESTONE_SERVER_CONNECT_END, "SERVER-CONNECT-END" }, + { TS_MILESTONE_SERVER_BEGIN_WRITE, "SERVER-BEGIN-WRITE" }, + { TS_MILESTONE_SERVER_FIRST_READ, "SERVER-FIRST-READ" }, + { TS_MILESTONE_SERVER_READ_HEADER_DONE, "SERVER-READ-HEADER-DONE" }, + { TS_MILESTONE_SERVER_CLOSE, "SERVER-CLOSE" }, + { TS_MILESTONE_CACHE_OPEN_READ_BEGIN, "CACHE-OPEN-READ-BEGIN" }, + { TS_MILESTONE_CACHE_OPEN_READ_END, "CACHE-OPEN-READ-END" }, + { TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN, "CACHE-OPEN-WRITE-BEGIN" }, + { TS_MILESTONE_CACHE_OPEN_WRITE_END, "CACHE-OPEN-WRITE-END" }, + { TS_MILESTONE_DNS_LOOKUP_BEGIN, "DNS-LOOKUP-BEGIN" }, + { TS_MILESTONE_DNS_LOOKUP_END, "DNS-LOOKUP-END" }, + }; + + TSMLoc dst = TS_NULL_MLOC; + TSHRTime epoch; + + // TS_MILESTONE_SM_START is stamped when the HTTP transaction is born. The slow + // log feature publishes the other times as seconds relative to this epoch. Let's + // do the same. + TSHttpTxnMilestoneGet(txn, TS_MILESTONE_SM_START, &epoch); + + // Create a new response header field. + dst = FindOrMakeHdrField(buffer, hdr, "X-Milestones", lengthof("X-Milestones")); + if (dst == TS_NULL_MLOC) { + goto done; + } + + for (unsigned i = 0; i < countof(milestones); ++i) { + TSHRTime time = 0; + char hdrval[64]; + + // If we got a milestone (it's in nanoseconds), convert it to seconds relative to + // the start of the transaction. We don't get milestone values for portions of the + // state machine the request doesn't traverse. + TSHttpTxnMilestoneGet(txn, milestones[i].mstype, &time); + if (time > 0) { + double elapsed = (double) (time - epoch) / 1000000000.0; + int len = (int)snprintf(hdrval, sizeof(hdrval), "%s=%1.9lf", milestones[i].msname, elapsed); + + TSReleaseAssert( + TSMimeHdrFieldValueStringInsert(buffer, hdr, dst, 0 /* idx */, hdrval, len) == TS_SUCCESS + ); + } + } + +done: + if (dst != TS_NULL_MLOC) { + TSHandleMLocRelease(buffer, hdr, dst); + } +} + static int XInjectResponseHeaders(TSCont /* contp */, TSEvent event, void * edata) { @@ -118,6 +188,10 @@ XInjectResponseHeaders(TSCont /* contp */, TSEvent event, void * edata) InjectCacheKeyHeader(txn, buffer, hdr); } + if (xheaders & XHEADER_X_MILESTONES) { + InjectMilestonesHeader(txn, buffer, hdr); + } + done: TSHttpTxnReenable(txn, TS_EVENT_HTTP_CONTINUE); return TS_EVENT_NONE; @@ -158,6 +232,8 @@ XScanRequestHeaders(TSCont /* contp */, TSEvent event, void * edata) if (strncasecmp("x-cache-key", value, vsize) == 0) { xheaders |= XHEADER_X_CACHE_KEY; + } else if (strncasecmp("x-milestones", value, vsize) == 0) { + xheaders |= XHEADER_X_MILESTONES; } else if (strncasecmp("via", value, vsize) == 0) { // If the client requests the Via header, enable verbose Via debugging for this transaction. TSHttpTxnConfigIntSet(txn, TS_CONFIG_HTTP_INSERT_RESPONSE_VIA_STR, 3); @@ -180,6 +256,7 @@ XScanRequestHeaders(TSCont /* contp */, TSEvent event, void * edata) } if (xheaders) { + TSDebug("xdebug", "adding response hook for header mask %p", (void *)xheaders); TSHttpTxnHookAdd(txn, TS_HTTP_SEND_RESPONSE_HDR_HOOK, XInjectHeadersCont); TSHttpTxnArgSet(txn, XArgIndex, (void *)xheaders); }
