feat: add support for before/after hooks to support tracing outbound requests

CHANGES.md

@@ -12,6 +12,9 @@
 ### Fix ###
 * #132: Handle multibyte characters properly in gzipped responses
 
+### New ###
+- #95: Add support for `before` and `after` hooks on client requests.
+
 ## 1.5.2
 
 - Switch back to restify-errors@3 to fix backward incompatiblity in

README.md

@@ -138,8 +138,10 @@ var client = restify.createJsonClient({
 |Name  | Type   | Description |
 | :--- | :----: | :---- |
 |accept|String|Accept header to send|
+|after|Function|Function for tracing. Run after every request, after the client has received the response.|
 |audit|Boolean|Enable Audit logging|
 |auditor|Function|Function for Audit logging|
+|before|Function|Function for tracing. Run before every request.|
 |connectTimeout|Number|Amount of time to wait for a socket|
 |contentType|String|Content-Type header to send|
 |requestTimeout|Number|Amount of time to wait for the request to finish|
@@ -488,6 +490,118 @@ Request timings are available under the `req.getTimings()` in milliseconds:
 All timings except `total` can be `null` under various circumstances like
 keep-alive connection, missing https etc.
 
+## Tracing
+
+This module allows the caller to add hook functions which will be called before
+and/or after each request from a JsonClient, StringClient or HttpClient. To
+utilize these hooks, you can pass the before and/or after options when creating
+the client. Any requests made by this client will then cause these functions to
+be called.
+
+These hooks are useful for integrating with a tracing framework such as
+[OpenTracing](http://opentracing.io/), as they allow passing in functions that
+add tracing for all outgoing requests made by your application.
+
+If passed, the value of the `before` parameter should be a function with the
+following prototype:
+
+```
+function before(opts, next) {
+```
+
+where `opts` is an object containing the options for the request, and `next`
+is a callback to call when processing is complete. Some things you might want to
+do in this before function include:
+
+ * writing a trace log message indicating that you're making a request
+ * modifying opts.headers to include additional headers in the outbound request
+
+Once processing is complete, the `before` function *must* call the `next`
+callback. If an object is passed as a parameter to `next` as in:
+
+```
+function before(opts, next) {
+    next({hello: 'world'});
+}
+```
+
+the object argument to next will be passed as an argument to the `after`
+function.
+
+If passed, the value of the `after` parameter should be a function with the
+following prototype:
+
+```
+function after(err, req, res, ctx, next) {
+```
+
+Where the parameters are:
+
+|Name  | Type   | Description |
+| :--- | :----: | :---- |
+|err|Error Object|The err object as returned by req.once('result', function (err, ...)|
+|req|Request Object|The [req](http://restify.com/#request-api) object for this request|
+|res|Response Object|The [res](http://restify.com/#response-api) object as returned by req.once('result', function (err, res)|
+|ctx|Object|The object passed by the `before` hook to its callback|
+|next|Function|The callback your handler must call when processing is complete|
+
+All of these parameters can also be `undefined` in cases where the value does
+not make sense. For example the `ctx` parameter will be `undefined` if `before`
+was not called or did not pass an object to its callback, and `req` and `res`
+will be undefined in error cases where a request failed early on.
+
+The `after` caller is most useful for logging the fact that a request completed
+and indicating errors or response details to a tracing system.
+
+A simple example of this tracing (missing any error checking) in action would be:
+
+```
+var restifyClients = require('restify-clients');
+
+var client = restifyClients.createJsonClient({
+    after: function _afterCb(err, req, res, ctx, next) {
+        console.error('AFTER: ' + JSON.stringify({
+            ctx: ctx,
+            statusCode: res.statusCode
+        }, null, 2));
+        next();
+    }, before: function _beforeCb(opts, next) {
+        console.error('BEFORE: ' + JSON.stringify({
+            headers: opts.headers
+        }, null, 2));
+        // set an additional header before the request is made
+        opts.headers['x-example-header'] = 'exemplary';
+        next({hello: 'from _beforeCb'});
+    }, url: 'http://127.0.0.1:8080'
+});
+
+// make a GET request to /hello
+client.get('/hello', function _getCb(err, req, res, obj) {
+    console.error('REQUEST COMPLETE');
+});
+```
+
+which, if run, should output something like:
+
+```
+BEFORE: {
+  "headers": {
+    "accept": "application/json",
+    "user-agent": "restify/1.4.1 (x64-darwin; v8/4.5.103.37; OpenSSL/1.0.2j) node/4.6.0",
+    "date": "Fri, 04 Nov 2016 06:06:42 GMT"
+  }
+}
+AFTER: {
+  "ctx": {
+    "hello": "from _beforeCb"
+  },
+  "statusCode": 200
+}
+REQUEST COMPLETE
+```
+
+assuming you have a server listening on 127.0.0.1:8080 responding to `GET /hello`.
+
 ## Contributing
 
 Add unit tests for any new or changed functionality. Ensure that lint and style

lib/HttpClient.js

@@ -460,6 +460,17 @@ function HttpClient(options) {
 
     this.key = options.key;
     this.name = options.name || 'HttpClient';
+
+    // add before and after hooks if they're passed
+
+    if (options.before) {
+        self._before = options.before;
+    }
+
+    if (options.after) {
+        self._after = options.after;
+    }
+
     this.passphrase = options.passphrase;
     this.pfx = options.pfx;
     this.query = options.query;
@@ -710,27 +721,76 @@ HttpClient.prototype.basicAuth = function basicAuth(username, password) {
     return (this);
 };
 
+function dummyBeforeHook(opts, next) {
+    next();
+}
+
+/* eslint-disable handle-callback-err */
+function dummyAfterHook(err, req, res, ctx, next) {
+    next();
+}
 
 HttpClient.prototype.request = function request(opts, cb) {
     assert.object(opts, 'options');
     assert.func(cb, 'callback');
 
+    var _rawRequest = rawRequest;
+    var self = this;
+
     /* eslint-disable no-param-reassign */
+    if (self._before || self._after) {
+        _rawRequest = function _wrappedRawRequest(_opts, _cb) {
+            var _after = self._after || dummyAfterHook;
+            var _before = self._before || dummyBeforeHook;
+
+            _before(opts, function _beforeCb(ctx) {
+                // Now call the original rawRequest but wrap the callback so we
+                // can hook in our after hook.
+                rawRequest(opts, function _rawRequestCb(err, req) {
+                    // We've now attempted to make the request. It doesn't seem
+                    // like there's a normal codepath where we get an `err` but
+                    // no `req` because even when you set the connectTimeout so
+                    // that happens immediately, it will still create a req. As
+                    // such, we verify here that we always have a req object.
+                    //
+                    // We'll call our _after() hook when that req emits 'result'
+                    // so that we have the 'res' parameter.
+
+                    assert.object(req, 'req');
+
+                    req.once('result', function _onResult(resErr, resRes) {
+                        _after(resErr, req, resRes, ctx,
+                            function _afterCb() {
+                                // When _after() calls its callback, we don't
+                                // currently do anything because we don't want
+                                // after to be able to delay requests. If we
+                                // did want that, we could move the call to
+                                // _cb() here.
+                            }
+                        );
+                    });
+
+                    // Call the original callback intended for rawRequest()
+                    _cb(err, req);
+                });
+            });
+        };
+    }
     cb = once(cb);
     /* eslint-enable no-param-reassign */
 
     opts.audit = this.audit;
 
     if (opts.retry === false) {
-        rawRequest(opts, cb);
+        _rawRequest(opts, cb);
         return;
     }
 
     var call;
     var retry = cloneRetryOptions(opts.retry);
 
     opts._keep_alive = this._keep_alive;
-    call = backoff.call(rawRequest, opts, cb);
+    call = backoff.call(_rawRequest, opts, cb);
     call.setStrategy(new backoff.ExponentialStrategy({
         initialDelay: retry.minTimeout,
         maxDelay: retry.maxTimeout

test/e2e.js

@@ -8,8 +8,8 @@ var clients = require('../lib');
 
 describe('restify-client tests against real web server', function () {
     it('have timings', function (done) {
-        var client = clients.createJsonClient({
-            url: 'https://netflix.com'
+        var client = clients.createStringClient({
+            url: 'https://www.netflix.com'
         });
 
         client.get('/', function (err, req, res) {
@@ -24,6 +24,7 @@ describe('restify-client tests against real web server', function () {
             assert.isNumber(timings.firstByte);
             assert.isNumber(timings.contentTransfer);
             assert.isNumber(timings.total);
+            client.close();
             done();
         });
     });