diff --git a/examples/trace/index.js b/examples/trace/index.js new file mode 100644 index 00000000000..f5d143fa9ac --- /dev/null +++ b/examples/trace/index.js @@ -0,0 +1,53 @@ +var debug = require('debug')('trace-example'); +var express = require('../../'); + +var app = express(); + +// Add a middleware that runs trace function. +app.use(function(req, res, next){ + res.start = Date.now() + res.id = random(); + res.trace('start', new Date()); + next(); +}); + +// Add another middleware that runs trace after an asynchronous call. +app.use(function(req, res, next){ + res.trace('wait:before'); + setTimeout(function () { + res.trace('wait:after'); + next(); + }, Math.random() * 100); +}) + +// Add a route to show request traces. +app.get('/', function(req, res, next){ + res.trace('user.id', random()); + res.trace('some.event', random(), random()); + res.trace('another.event', random(), random()); + res.set('X-Response-Time', (Date.now() - res.start) + 'ms'); + res.send('Hello world!'); + next(); +}); + +// Add an after request processing middleware that runs trace. +app.use(function(req, res, next){ + res.trace('finish'); +}); + +// Configure tracer. +app.instrument(function(options){ + debug(options.res.id, options.event, options.args.join(' ')); +}); + +// Helpers to generate random ids. +function random(){ + return Math.random().toString(36).slice(2); +}; + + +/* istanbul ignore next */ +if (!module.parent) { + app.listen(3000); + console.log('Express started on port 3000'); +} diff --git a/lib/application.js b/lib/application.js index 0ee4def3890..35eea5d0da6 100644 --- a/lib/application.js +++ b/lib/application.js @@ -57,6 +57,7 @@ app.init = function init() { this.cache = {}; this.engines = {}; this.settings = {}; + this.tracers = []; this.defaultConfiguration(); }; @@ -98,6 +99,10 @@ app.defaultConfiguration = function defaultConfiguration() { this.response.__proto__ = parent.response; this.engines.__proto__ = parent.engines; this.settings.__proto__ = parent.settings; + + this.instrument(function callParentTracer(options) { + parent._callTracers(options.res, options.event, options.args); + }); }); // setup locals @@ -617,6 +622,63 @@ app.listen = function listen() { return server.listen.apply(server, arguments); }; +/* + * Set a tracer at the application level. Tracer will be activated when a + * tracing call will be fired by a response. + * The tracer function takes an option object as argument with the given + * attributes: + * + * - app: current application + * - res: response that fires the tracer + * - req: request related to above response + * - event: string describing the event to trace + * - date: when the tracing occurs + * - args: allow to freely add information + * + * @param {function} The tracer to set. + * @return {app} for chaining. + * @public + */ + +app.instrument = function(tracer){ + if (tracer === undefined || typeof tracer !== 'function') + throw new TypeError('instrument expects a function'); + this.tracers.push(tracer); + return this; +}; + +/* + * Call all tracers set on the application. Add context information: + * running app, request, response and date. The date is the when the tracing + * was fired (now). + * + * @param {Response} Response that fires the tracing event. + * @param {Event} The event to trace. + * @param {Array} Arguments to transmit to the tracker. + * + * @private + */ + +app._callTracers = function(res, event, args){ + var date = new Date(); + var app = this; + var tracers = this.tracers; + var length = tracers.length; + + var options = { + app: app, + res: res, + req: res.req, + event: event, + date: date, + args: args + }; + + for (var i = 0; i < length; i++) { + tracers[i](options); + } +}; + /** * Log error using console.error. * diff --git a/lib/response.js b/lib/response.js index 6128f450a94..73393606ffd 100644 --- a/lib/response.js +++ b/lib/response.js @@ -1051,6 +1051,34 @@ function sendfile(res, file, options, callback) { file.pipe(res); } +/** + * Run every tracers set at the application level for given events + * and arguments. To set a tracer on the application use the `instrument` + * method. + * + * @param {function} event The event to trace. + * @return {ServerResponse} for chaining + * @public + */ + +res.trace = function(event) { + var args; + switch (arguments.length) { + case 0: + throw new Error('No event defined!'); + case 1: + args = []; + break; + case 2: + args = [arguments[1]]; + break; + default: + args = [].slice.call(arguments, 1); + } + this.app._callTracers(this, event, args); + return this; +}; + /** * Stringify JSON, like JSON.stringify, but v8 optimized. * @private diff --git a/test/app.instrument.js b/test/app.instrument.js new file mode 100644 index 00000000000..6a3994aecc1 --- /dev/null +++ b/test/app.instrument.js @@ -0,0 +1,23 @@ + +var express = require('../'); + +describe('app', function(){ + describe('.instrument(fn)', function(){ + it('should add function to the tracer list', function(){ + var app = express(); + function debug (options) { + console.log(options.event); + } + app.instrument(debug); + debug.should.be.equal(app.tracers[0]); + }); + + it('should throw err if tracer is not a function', function(){ + var app = express(); + + (function(){ + app.instrument('notatracer'); + }).should.throw('instrument expects a function'); + }); + }) +}) diff --git a/test/res.trace.js b/test/res.trace.js new file mode 100644 index 00000000000..c21366177b1 --- /dev/null +++ b/test/res.trace.js @@ -0,0 +1,98 @@ + +var express = require('../'); +var request = require('supertest'); +var assert = require('assert'); + +describe('res', function(){ + describe('.trace(event)', function(){ + it('should call all tracers set at application level', function(done){ + var app = express(); + + app.instrument(function(options){ + assert.equal(options.app, app) + assert.equal(options.req.url, '/'); + assert.equal(options.res.id, '1'); + assert.equal(options.event, 'one:event'); + assert.equal(options.args[0], 'info'); + }); + + app.use(function(req, res, next){ + res.id = '1'; + res.trace('one:event', 'info'); + next(); + }); + + app.get('/', function(req, res){ + res.send('ok'); + }); + + request(app) + .get('/') + .expect(200, done); + }) + }) + + describe('.trace(event) with parents', function(){ + it('should call parent tracers too', function(done){ + + var app = express(); + var appParent1 = express(); + var appParent2 = express(); + + var parentTraces1 = []; + var parentTraces2 = []; + + appParent1.instrument(function(options){ + assert.equal(options.req.id, '1'); + parentTraces1.push(options.event + ':parent1'); + }); + + appParent2.instrument(function(options){ + assert.equal(options.req.id, '1'); + parentTraces2.push(options.event + ':parent2'); + }); + + appParent1.use('/childof1', app); + appParent2.use('/childof2', app); + app.instrument(function(options){ + assert.equal(options.event, 'one:event'); + assert.equal(options.args[0], 'info'); + }); + + app.use(function(req, res, next){ + req.id = '1'; + next(); + }); + + app.get('/', function(req, res){ + res.trace('one:event', 'info'); + res.send('ok'); + }); + + request(appParent1) + .get('/childof1') + .expect(200, function(err){ + if (err) return done(err); + + assert.equal(parentTraces1.length, 1); + assert.equal(parentTraces2.length, 1); + assert.equal(parentTraces1[0], 'one:event:parent1'); + assert.equal(parentTraces2[0], 'one:event:parent2'); + + request(appParent2) + .get('/childof2') + .expect(200, function(err){ + if (err) return done(err); + + assert.equal(parentTraces1.length, 2); + assert.equal(parentTraces2.length, 2); + assert.equal(parentTraces1[0], 'one:event:parent1'); + assert.equal(parentTraces2[0], 'one:event:parent2'); + assert.equal(parentTraces1[1], 'one:event:parent1'); + assert.equal(parentTraces2[1], 'one:event:parent2'); + done(); + }); + }); + }); + }) +});