On Apr 10, 2014, at 5:54 AM, zw...@apache.org wrote:
> Repository: trafficserver
> Updated Branches:
> refs/heads/master 4b6c8e022 -> 77c5cf39b
>
>
> TS-2703 Add a text log format to escalate plugin
>
>
> Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo
> Commit: http://git-wip-us.apache.org/repos/asf/trafficserver/commit/77c5cf39
> Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/77c5cf39
> Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/77c5cf39
>
> Branch: refs/heads/master
> Commit: 77c5cf39b0719c7e8d8855070452644379df2ea1
> Parents: 4b6c8e0
> Author: Leif Hedstrom <zw...@apache.org>
> Authored: Mon Apr 7 14:23:45 2014 -0600
> Committer: Leif Hedstrom <zw...@apache.org>
> Committed: Thu Apr 10 06:54:37 2014 -0600
>
> ----------------------------------------------------------------------
> .../background_fetch/background_fetch.cc | 101 ++++++++++++++++---
> 1 file changed, 89 insertions(+), 12 deletions(-)
> ----------------------------------------------------------------------
>
>
> http://git-wip-us.apache.org/repos/asf/trafficserver/blob/77c5cf39/plugins/experimental/background_fetch/background_fetch.cc
> ----------------------------------------------------------------------
> diff --git a/plugins/experimental/background_fetch/background_fetch.cc
> b/plugins/experimental/background_fetch/background_fetch.cc
> index 297bd7d..13223bd 100644
> --- a/plugins/experimental/background_fetch/background_fetch.cc
> +++ b/plugins/experimental/background_fetch/background_fetch.cc
> @@ -22,12 +22,11 @@
> limitations under the License.
>
> */
> -
> -
> -
> #include <stdio.h>
> #include <string.h>
> #include <string>
> +#include <stdarg.h>
> +#include <getopt.h>
>
> #include <netinet/in.h>
> #include <arpa/inet.h>
> @@ -168,6 +167,12 @@ public:
> // ToDo: Destroy mutex ? TS-1432
> }
>
> + void create_log(const char* log_name)
> + {
> + TSDebug(PLUGIN_NAME, "Creating log name %s\n", log_name);
> + TSAssert(TS_SUCCESS == TSTextLogObjectCreate(log_name,
> TS_LOG_MODE_ADD_TIMESTAMP, &log));
> + }
> +
> bool acquire(const std::string &url)
> {
> bool ret;
> @@ -200,12 +205,14 @@ public:
> return ret;
> }
>
> + TSTextLogObject log;
> +
> private:
> OutstandingRequests _urls;
> TSMutex _lock;
> };
>
> -BGFetchConfig gConfig;
> +BGFetchConfig* gConfig;
>
> //////////////////////////////////////////////////////////////////////////////
> // Hold and manage some state for the background fetch continuation
> @@ -215,8 +222,8 @@ static int cont_bg_fetch(TSCont contp, TSEvent event,
> void* edata);
>
> struct BGFetchData
> {
> - BGFetchData(BGFetchConfig* cfg=&gConfig)
> - : hdr_loc(TS_NULL_MLOC), url_loc(TS_NULL_MLOC), _cont(NULL),
> _config(cfg)
> + BGFetchData(BGFetchConfig* cfg=gConfig)
> + : hdr_loc(TS_NULL_MLOC), url_loc(TS_NULL_MLOC), vc(NULL), _bytes(0),
> _cont(NULL), _config(cfg)
> {
> mbuf = TSMBufferCreate();
> }
> @@ -230,6 +237,12 @@ struct BGFetchData
>
> TSMBufferDestroy(mbuf);
>
> + if (vc) {
> + TSError("%s: Destroyed BGFetchDATA while VC was alive", PLUGIN_NAME);
> + TSVConnClose(vc);
> + vc = NULL;
> + }
> +
> // If we got schedule, also clean that up
> if (_cont) {
> TSContDestroy(_cont);
> @@ -245,9 +258,11 @@ struct BGFetchData
> bool release_url() const { return _config->release(_url); }
>
> const char* get_url() const { return _url.c_str(); }
> + void add_bytes(int64_t b) { _bytes += b; }
>
> bool initialize(TSMBuffer request, TSMLoc req_hdr, TSHttpTxn txnp);
> void schedule();
> + void log(TSEvent event) const;
>
> TSMBuffer mbuf;
> TSMLoc hdr_loc;
> @@ -262,6 +277,7 @@ struct BGFetchData
>
> private:
> std::string _url;
> + int64_t _bytes;
> TSCont _cont;
> BGFetchConfig* _config;
> };
> @@ -353,6 +369,39 @@ BGFetchData::schedule()
> }
>
>
> +// Log format is:
> +// remap-tag bytes status url
> +void
> +BGFetchData::log(TSEvent event) const
> +{
> + BGFetchConfig* conf = _config ? _config : gConfig;
> +
> + if (conf->log) {
> + const char* status;
> +
> + switch (event) {
> + case TS_EVENT_VCONN_EOS:
> + status = "EOS";
> + break;
> + case TS_EVENT_VCONN_INACTIVITY_TIMEOUT:
> + status = "TIMEOUT";
> + break;
> + case TS_EVENT_ERROR:
> + status = "ERROR";
> + case TS_EVENT_VCONN_READ_COMPLETE:
> + status = "READ_COMP";
I think that "COMPLETE" would be a clearer tag and match the other tags better.
> + break;
> + default:
> + status = "UNKNOWN";
> + break;
> + }
> +
> + // ToDo: Also deal with per-remap tagging
> + TSTextLogObjectWrite(conf->log, "%s %" PRId64 " %s %s", "-", _bytes,
> status, _url.c_str());
> + }
> +}
> +
> +
> //////////////////////////////////////////////////////////////////////////////
> // Continuation to perform a background fill of a URL. This is pretty
> // expensive (memory allocations etc.), we could eliminate maybe the
> @@ -389,13 +438,15 @@ cont_bg_fetch(TSCont contp, TSEvent event, void* /*
> edata ATS_UNUSED */)
> }
>
> // Setup the NetVC for background fetch
> + TSAssert(NULL == data->vc);
> if ((data->vc = TSHttpConnect((sockaddr*)&data->client_ip)) != NULL) {
> TSHttpHdrPrint(data->mbuf, data->hdr_loc, data->req_io_buf);
> // We never send a body with the request. ToDo: Do we ever need to
> support that ?
> TSIOBufferWrite(data->req_io_buf, "\r\n", 2);
>
> data->r_vio = TSVConnRead(data->vc, contp, data->resp_io_buf,
> INT64_MAX);
> - data->w_vio = TSVConnWrite(data->vc, contp, data->req_io_buf_reader,
> TSIOBufferReaderAvail(data->req_io_buf_reader));
> + data->w_vio = TSVConnWrite(data->vc, contp, data->req_io_buf_reader,
> +
> TSIOBufferReaderAvail(data->req_io_buf_reader));
> } else {
> delete data;
> TSError("%s: failed to connect to internal process, major malfunction",
> PLUGIN_NAME);
> @@ -407,6 +458,7 @@ cont_bg_fetch(TSCont contp, TSEvent event, void* /* edata
> ATS_UNUSED */)
>
> case TS_EVENT_VCONN_READ_READY:
> avail = TSIOBufferReaderAvail(data->resp_io_buf_reader);
> + data->add_bytes(avail);
> TSIOBufferReaderConsume(data->resp_io_buf_reader, avail);
> TSVIONDoneSet(data->r_vio, TSVIONDoneGet(data->r_vio) + avail);
> TSVIOReenable(data->r_vio);
> @@ -415,6 +467,7 @@ cont_bg_fetch(TSCont contp, TSEvent event, void* /* edata
> ATS_UNUSED */)
> case TS_EVENT_VCONN_READ_COMPLETE:
> case TS_EVENT_VCONN_EOS:
> case TS_EVENT_VCONN_INACTIVITY_TIMEOUT:
> + case TS_EVENT_ERROR:
> if (event == TS_EVENT_VCONN_INACTIVITY_TIMEOUT) {
> TSDebug(PLUGIN_NAME, "Encountered Inactivity Timeout");
> TSVConnAbort(data->vc, TS_VC_CLOSE_ABORT);
> @@ -422,18 +475,20 @@ cont_bg_fetch(TSCont contp, TSEvent event, void* /*
> edata ATS_UNUSED */)
> TSVConnClose(data->vc);
> }
>
> - // ToDo: Is this really necessary to do here for all 3 cases?
> - TSDebug(PLUGIN_NAME, "Closing down background transaction, event=%d",
> event);
> + TSDebug(PLUGIN_NAME, "Closing down background transaction, event=
> %s(%d)", TSHttpEventNameLookup(event), event);
> avail = TSIOBufferReaderAvail(data->resp_io_buf_reader);
> + data->add_bytes(avail);
> TSIOBufferReaderConsume(data->resp_io_buf_reader, avail);
> TSVIONDoneSet(data->r_vio, TSVIONDoneGet(data->r_vio) + avail);
>
> - // Release and Cleanup
> + data->log(event);
> + data->vc = NULL;
> + // Close, release and cleanup
> delete data;
> break;
>
> default:
> - TSDebug(PLUGIN_NAME, "Unhandled event: %d", event); // ToDo: use new API
> in v5.0.0
> + TSDebug(PLUGIN_NAME, "Unhandled event: %s (%d)",
> TSHttpEventNameLookup(event), event);
> break;
> }
>
> @@ -535,9 +590,13 @@ cont_handle_response(TSCont /* contp ATS_UNUSED */,
> TSEvent /* event ATS_UNUSED
> ///////////////////////////////////////////////////////////////////////////
> // Setup global hooks
> void
> -TSPluginInit(int /* argc ATS_UNUSED */, const char* /* argv ATS_UNUSED */[])
> +TSPluginInit(int argc, const char* argv[])
> {
> TSPluginRegistrationInfo info;
> + static const struct option longopt[] = {
> + { "log", required_argument, NULL, 'l' },
> + {NULL, no_argument, NULL, '\0' }
> + };
>
> info.plugin_name = (char*)PLUGIN_NAME;
> info.vendor_name = (char*)"Apache Software Foundation";
> @@ -547,6 +606,24 @@ TSPluginInit(int /* argc ATS_UNUSED */, const char* /*
> argv ATS_UNUSED */[])
> TSError("%s: plugin registration failed.\n", PLUGIN_NAME);
> }
>
> + gConfig = new BGFetchConfig();
> + optind = 1;
> +
> + while (true) {
> + int opt = getopt_long(argc, (char * const *)argv, "l", longopt, NULL);
> +
> + switch (opt) {
> + case 'l':
> + gConfig->create_log(optarg);
> + break;
> + }
> +
> + if (opt == -1) {
> + break;
> + }
> + }
> +
> +
> TSDebug(PLUGIN_NAME, "Initialized");
> TSHttpHookAdd(TS_HTTP_READ_RESPONSE_HDR_HOOK,
> TSContCreate(cont_handle_response, NULL));
> }
>
