diff --git a/index.js b/index.js index 0c7d45e2b..070c3458b 100644 --- a/index.js +++ b/index.js @@ -1,4 +1,5 @@ 'use strict'; +var prettyMs = require('pretty-ms'); var chalk = require('chalk'); var figures = require('figures'); var Squeak = require('squeak'); @@ -17,13 +18,27 @@ log.type('error', { prefix: figures.cross }); -function test(err, title) { +function test(err, title, duration) { if (err) { log.error(title, chalk.red(err.message)); return; } - log.success(title); + // format a time spent in the test + var timeSpent = ''; + + // display duration only over a threshold + var threshold = 100; + + if (duration > threshold) { + var formattedDuration = prettyMs(duration, { + secDecimalDigits: 2 + }); + + timeSpent = chalk.gray.dim(' (' + formattedDuration + ')'); + } + + log.success(title + timeSpent); } function stack(results) { diff --git a/lib/runner.js b/lib/runner.js index dd33bfc59..6df9b914c 100644 --- a/lib/runner.js +++ b/lib/runner.js @@ -36,17 +36,18 @@ Runner.prototype.addSerialTest = function (title, cb) { Runner.prototype.concurrent = function (cb) { each(this.tests.concurrent, function (test, i, next) { - test.run(function (err) { + test.run(function (err, duration) { if (err) { this.stats.failCount++; } this.results.push({ + duration: duration, title: test.title, error: err }); - this.emit('test', err, test.title); + this.emit('test', err, test.title, duration); next(); }.bind(this)); }.bind(this), cb); @@ -54,17 +55,18 @@ Runner.prototype.concurrent = function (cb) { Runner.prototype.serial = function (cb) { eachSerial(this.tests.serial, function (test, next) { - test.run(function (err) { + test.run(function (err, duration) { if (err) { this.stats.failCount++; } this.results.push({ + duration: duration, title: test.title, error: err }); - this.emit('test', err, test.title); + this.emit('test', err, test.title, duration); next(); }.bind(this)); }.bind(this), cb); diff --git a/lib/test.js b/lib/test.js index 962f7bf48..8a21d2eff 100644 --- a/lib/test.js +++ b/lib/test.js @@ -21,6 +21,12 @@ function Test(title, fn) { this.fn = fn; this.assertCount = 0; this.planCount = null; + this.duration = null; + + // store the time point + // before test execution + // to calculate the total time spent in test + this._timeStart = null; } util.inherits(Test, EventEmitter); @@ -67,6 +73,8 @@ Test.prototype.run = function (cb) { this.exit(); } + this._timeStart = Date.now(); + try { var ret = this.fn(this); @@ -98,6 +106,9 @@ Test.prototype.end = function () { }; Test.prototype.exit = function () { + // calculate total time spent in test + this.duration = Date.now() - this._timeStart; + if (this.planCount !== null && this.planCount !== this.assertCount) { this.assertError = new assert.AssertionError({ actual: this.assertCount, @@ -113,7 +124,7 @@ Test.prototype.exit = function () { this.ended = true; setImmediate(function () { - this.cb(this.assertError); + this.cb(this.assertError, this.duration); }.bind(this)); } }; diff --git a/package.json b/package.json index 17a18e310..70ec469ef 100644 --- a/package.json +++ b/package.json @@ -54,6 +54,7 @@ "globby": "^2.0.0", "meow": "^3.3.0", "plur": "^2.0.0", + "pretty-ms": "^2.0.0", "squeak": "^1.2.0", "update-notifier": "^0.5.0" }, diff --git a/test/test.js b/test/test.js index fbec14a6d..a746588c7 100644 --- a/test/test.js +++ b/test/test.js @@ -343,3 +343,21 @@ test('promise support - reject', function (t) { t.end(); }); }); + +test('record test duration', function (t) { + var avaTest; + + ava(function (a) { + avaTest = a; + + a.plan(1); + + setTimeout(function () { + a.true(true); + }, 1234); + }).run(function (err) { + t.false(err); + t.true(avaTest.duration >= 1234); + t.end(); + }); +});