Put back the # time=... directives

tapjs · Jan 26, 2017 · f63ea3e · f63ea3e
1 parent 6a6faf0
commit f63ea3e
Show file tree

Hide file tree

Showing 251 changed files with 832 additions and 818 deletions.
diff --git a/lib/base.js b/lib/base.js
@@ -21,6 +21,8 @@ var ownOrEnv = require('own-or-env')
 
 function Base (options) {
   this.start = 0
+  this.hrtime = null
+  this.time = null
   this.readyToProcess = false
   this.options = options
   this.parent = ownOr(options, 'parent', null)
@@ -58,6 +60,9 @@ Base.prototype.passing = function () {
 }
 
 Base.prototype.setTimeout = function (n) {
+  if (!this.hrtime)
+    this.hrtime = process.hrtime()
+
   if (!n) {
     clearTimeout(this.timer)
     this.timer = null
@@ -131,6 +136,11 @@ Base.prototype.onbail = function (reason) {
 }
 
 Base.prototype.oncomplete = function (results) {
+  if (this.hrtime) {
+    this.hrtime = process.hrtime(this.hrtime)
+    this.time = Math.round(this.hrtime[0] * 1e6 + this.hrtime[1] / 1e3) / 1e3
+  }
+
   this.debug('ONCOMPLETE %j %j', this.name, results)
   this.results = results
   this.emit('complete', results)

diff --git a/lib/clean-yaml-object.js b/lib/clean-yaml-object.js
@@ -46,6 +46,7 @@ function yamlFilter (propertyName, isRoot, source, target) {
   }
 
   return !(propertyName === 'todo' ||
+  propertyName === 'time' ||
   /^_?tapChild/.test(propertyName) ||
   /^tapStream/.test(propertyName) ||
   /^tapMochaTest/.test(propertyName) ||

diff --git a/lib/point.js b/lib/point.js
@@ -31,7 +31,8 @@ function tpMessage (message, extra) {
     message += ' # TODO'
     if (typeof extra.todo === 'string')
       message += ' ' + extra.todo
-  }
+  } else if (extra.time)
+    message += ' # time=' + extra.time + 'ms'
 
   var diagYaml = extra.diagnostic ? diags(extra) : ''
   message += diagYaml

diff --git a/lib/tap.js b/lib/tap.js
@@ -14,6 +14,7 @@ function TAP (options) {
 var didPipe = false
 TAP.prototype.pipe = function () {
   didPipe = true
+  this.setTimeout(this.options.timeout)
   this.pipe = Test.prototype.pipe
   this.push = Test.prototype.push
   return this.pipe.apply(this, arguments)
@@ -37,6 +38,8 @@ TAP.prototype.onbail = function () {
 }
 
 TAP.prototype.ondone = function () {
+  if (didPipe && this.time)
+    this.emit('data', '# time=' + this.time + 'ms\n')
   this.emit('teardown')
 }
 

diff --git a/lib/test.js b/lib/test.js
@@ -320,6 +320,8 @@ Test.prototype.onbufferedend = function (p, er) {
   this.pool.remove(p)
   p.options.tapChildBuffer = p.output || ''
   p.options.stack = ''
+  if (p.time)
+    p.options.time = p.time
   if (this.occupied === p)
     this.occupied = null
   if (er)
@@ -337,6 +339,8 @@ Test.prototype.onindentedend = function (p, er) {
     this.subtests.splice(sti, 1)
   p.readyToProcess = true
   p.results = p.results || {}
+  if (p.time)
+    p.options.time = p.time
   var to = p.options.timeout
   if (to && p.passing())
     var dur = Date.now() - p.start

diff --git a/test/test/assert-at--bail--buffer.tap b/test/test/assert-at--bail--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-not ok 1 - foo {
+not ok 1 - foo ___/# time=[0-9.]+(ms)?/~~~ {
     not ok 1 - baz
       ---
       {"at":{"column":3,"file":"test/test/assert-at.js","function":"baz","line":14},"source":"blo(t)\n"}

diff --git a/test/test/assert-at--buffer.tap b/test/test/assert-at--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-not ok 1 - foo {
+not ok 1 - foo ___/# time=[0-9.]+(ms)?/~~~ {
     not ok 1 - baz
       ---
       {"at":{"column":3,"file":"test/test/assert-at.js","function":"baz","line":14},"source":"blo(t)\n"}

diff --git a/test/test/assert-at.tap b/test/test/assert-at.tap
@@ -22,7 +22,7 @@ TAP version 13
 
     1..4
     # failed 4 of 4 tests
-not ok 1 - foo
+not ok 1 - foo ___/# time=[0-9.]+(ms)?/~~~
 
 1..1
 # failed 1 test

diff --git a/test/test/assert-todo-skip--bail--buffer.tap b/test/test/assert-todo-skip--bail--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-ok 1 - not much {
+ok 1 - not much ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - always passes # SKIP skip it good
     not ok 2 - false # SKIP always fails
     ok 3 - bonus # TODO remove todo directive

diff --git a/test/test/assert-todo-skip--bail.tap b/test/test/assert-todo-skip--bail.tap
@@ -19,7 +19,7 @@ TAP version 13
     1..8
     # todo: 4
     # skip: 4
-ok 1 - not much
+ok 1 - not much ___/# time=[0-9.]+(ms)?/~~~
 
 1..1
 
diff --git a/test/test/assert-todo-skip--buffer.tap b/test/test/assert-todo-skip--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-ok 1 - not much {
+ok 1 - not much ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - always passes # SKIP skip it good
     not ok 2 - false # SKIP always fails
     ok 3 - bonus # TODO remove todo directive

diff --git a/test/test/assert-todo-skip.tap b/test/test/assert-todo-skip.tap
@@ -19,7 +19,7 @@ TAP version 13
     1..8
     # todo: 4
     # skip: 4
-ok 1 - not much
+ok 1 - not much ___/# time=[0-9.]+(ms)?/~~~
 
 1..1
 
diff --git a/test/test/async--bail--buffer.tap b/test/test/async--bail--buffer.tap
@@ -1,10 +1,10 @@
 TAP version 13
-ok 1 - first test {
+ok 1 - first test ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - this is ok
     1..1
 }
 
-ok 2 - second test (async) {
+ok 2 - second test (async) ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - this is ok
     1..1
 }

diff --git a/test/test/async--bail.tap b/test/test/async--bail.tap
@@ -2,12 +2,12 @@ TAP version 13
 # Subtest: first test
     ok 1 - this is ok
     1..1
-ok 1 - first test
+ok 1 - first test ___/# time=[0-9.]+(ms)?/~~~
 
 # Subtest: second test (async)
     ok 1 - this is ok
     1..1
-ok 2 - second test (async)
+ok 2 - second test (async) ___/# time=[0-9.]+(ms)?/~~~
 
 1..2
 
diff --git a/test/test/async--buffer.tap b/test/test/async--buffer.tap
@@ -1,10 +1,10 @@
 TAP version 13
-ok 1 - first test {
+ok 1 - first test ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - this is ok
     1..1
 }
 
-ok 2 - second test (async) {
+ok 2 - second test (async) ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - this is ok
     1..1
 }

diff --git a/test/test/async.tap b/test/test/async.tap
@@ -2,12 +2,12 @@ TAP version 13
 # Subtest: first test
     ok 1 - this is ok
     1..1
-ok 1 - first test
+ok 1 - first test ___/# time=[0-9.]+(ms)?/~~~
 
 # Subtest: second test (async)
     ok 1 - this is ok
     1..1
-ok 2 - second test (async)
+ok 2 - second test (async) ___/# time=[0-9.]+(ms)?/~~~
 
 1..2
 
diff --git a/test/test/bail-child--bail--buffer.tap b/test/test/bail-child--bail--buffer.tap
@@ -1,6 +1,6 @@
 TAP version 13
-not ok 1 - bail fail {
-    not ok 1 - failer {
+not ok 1 - bail fail ___/# time=[0-9.]+(ms)?/~~~ {
+    not ok 1 - failer ___/# time=[0-9.]+(ms)?/~~~ {
         not ok 1 - this fails
           ---
           {"at":{"column":7,"file":"test/test/bail-child.js","line":7},"source":"t.fail('this fails')\n"}

diff --git a/test/test/bail-child--buffer.tap b/test/test/bail-child--buffer.tap
@@ -1,6 +1,6 @@
 TAP version 13
-not ok 1 - bail fail {
-    not ok 1 - failer {
+not ok 1 - bail fail ___/# time=[0-9.]+(ms)?/~~~ {
+    not ok 1 - failer ___/# time=[0-9.]+(ms)?/~~~ {
         not ok 1 - this fails
           ---
           {"at":{"column":7,"file":"test/test/bail-child.js","line":7},"source":"t.fail('this fails')\n"}

diff --git a/test/test/bail-fail-spawn--bail--buffer.tap b/test/test/bail-fail-spawn--bail--buffer.tap
@@ -1,19 +1,19 @@
 TAP version 13
-not ok 1 - bail fail {
-    not ok 1 - ___/.*(node|iojs)(.exe)?/~~~ ./test/test/nesting.js
+not ok 1 - bail fail ___/# time=[0-9.]+(ms)?/~~~ {
+    not ok 1 - ___/.*(node|iojs)(.exe)?/~~~ ./test/test/nesting.js ___/# time=[0-9.]+(ms)?/~~~
       ---
       {"args":["___/.*/~~~nesting.js"],"command":"___/.*(node|iojs)(.exe)?/~~~","cwd":"___/.*/~~~","exitCode":1}
       ...
     {
-        not ok 1 - nesting {
+        not ok 1 - nesting ___/# time=[0-9.]+(ms)?/~~~ {
             1..2
-            ok 1 - first {
+            ok 1 - first ___/# time=[0-9.]+(ms)?/~~~ {
                 1..2
                 ok 1 - true is ok
                 ok 2 - doag is also okay
             }
 
-            not ok 2 - second {
+            not ok 2 - second ___/# time=[0-9.]+(ms)?/~~~ {
                 ok 1 - but that is ok
                 ok 2 - this passes
                 not ok 3 - nested failure

diff --git a/test/test/bail-fail-spawn--bail.tap b/test/test/bail-fail-spawn--bail.tap
@@ -7,7 +7,7 @@ TAP version 13
                 1..2
                 ok 1 - true is ok
                 ok 2 - doag is also okay
-            ok 1 - first
+            ok 1 - first ___/# time=[0-9.]+(ms)?/~~~
 
             # Subtest: second
                 ok 1 - but that is ok

diff --git a/test/test/bail-fail-spawn--buffer.tap b/test/test/bail-fail-spawn--buffer.tap
@@ -1,19 +1,19 @@
 TAP version 13
-not ok 1 - bail fail {
-    not ok 1 - ___/.*(node|iojs)(.exe)?/~~~ ./test/test/nesting.js
+not ok 1 - bail fail ___/# time=[0-9.]+(ms)?/~~~ {
+    not ok 1 - ___/.*(node|iojs)(.exe)?/~~~ ./test/test/nesting.js ___/# time=[0-9.]+(ms)?/~~~
       ---
       {"args":["___/.*/~~~nesting.js"],"command":"___/.*(node|iojs)(.exe)?/~~~","cwd":"___/.*/~~~","exitCode":1}
       ...
     {
-        not ok 1 - nesting {
+        not ok 1 - nesting ___/# time=[0-9.]+(ms)?/~~~ {
             1..2
-            ok 1 - first {
+            ok 1 - first ___/# time=[0-9.]+(ms)?/~~~ {
                 1..2
                 ok 1 - true is ok
                 ok 2 - doag is also okay
             }
 
-            not ok 2 - second {
+            not ok 2 - second ___/# time=[0-9.]+(ms)?/~~~ {
                 ok 1 - but that is ok
                 ok 2 - this passes
                 not ok 3 - nested failure

diff --git a/test/test/bail-fail-spawn.tap b/test/test/bail-fail-spawn.tap
@@ -7,7 +7,7 @@ TAP version 13
                 1..2
                 ok 1 - true is ok
                 ok 2 - doag is also okay
-            ok 1 - first
+            ok 1 - first ___/# time=[0-9.]+(ms)?/~~~
 
             # Subtest: second
                 ok 1 - but that is ok

diff --git a/test/test/bail-teardown--bail--buffer.tap b/test/test/bail-teardown--bail--buffer.tap
@@ -1,6 +1,6 @@
 TAP version 13
 ok 1 - this is fine
-ok 2 - child {
+ok 2 - child ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - child test point
     1..1
 }

diff --git a/test/test/bail-teardown--bail.tap b/test/test/bail-teardown--bail.tap
@@ -3,7 +3,7 @@ ok 1 - this is fine
 # Subtest: child
     ok 1 - child test point
     1..1
-ok 2 - child
+ok 2 - child ___/# time=[0-9.]+(ms)?/~~~
 
 Bail out! # i did not want to be torn down
 
diff --git a/test/test/bail-teardown--buffer.tap b/test/test/bail-teardown--buffer.tap
@@ -1,6 +1,6 @@
 TAP version 13
 ok 1 - this is fine
-ok 2 - child {
+ok 2 - child ___/# time=[0-9.]+(ms)?/~~~ {
     ok 1 - child test point
     1..1
 }

diff --git a/test/test/bail-teardown-async--bail--buffer.tap b/test/test/bail-teardown-async--bail--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-ok 1 - foobar test {
+ok 1 - foobar test ___/# time=[0-9.]+(ms)?/~~~ {
     1..0
 }
 

diff --git a/test/test/bail-teardown-async--bail.tap b/test/test/bail-teardown-async--bail.tap
@@ -1,7 +1,7 @@
 TAP version 13
 # Subtest: foobar test
     1..0
-ok 1 - foobar test
+ok 1 - foobar test ___/# time=[0-9.]+(ms)?/~~~
 
 # Subtest: barfoo
 Bail out! # teardown fail

diff --git a/test/test/bail-teardown-async--buffer.tap b/test/test/bail-teardown-async--buffer.tap
@@ -1,5 +1,5 @@
 TAP version 13
-ok 1 - foobar test {
+ok 1 - foobar test ___/# time=[0-9.]+(ms)?/~~~ {
     1..0
 }
 

diff --git a/test/test/bail-teardown-async.tap b/test/test/bail-teardown-async.tap
@@ -1,7 +1,7 @@
 TAP version 13
 # Subtest: foobar test
     1..0
-ok 1 - foobar test
+ok 1 - foobar test ___/# time=[0-9.]+(ms)?/~~~
 
 # Subtest: barfoo
 Bail out! # teardown fail

diff --git a/test/test/bail-teardown.tap b/test/test/bail-teardown.tap
@@ -3,7 +3,7 @@ ok 1 - this is fine
 # Subtest: child
     ok 1 - child test point
     1..1
-ok 2 - child
+ok 2 - child ___/# time=[0-9.]+(ms)?/~~~
 
 Bail out! # i did not want to be torn down
 
diff --git a/test/test/bailout--bail--buffer.tap b/test/test/bailout--bail--buffer.tap
@@ -1,13 +1,13 @@
 TAP version 13
-ok 1 - nesting {
+ok 1 - nesting ___/# time=[0-9.]+(ms)?/~~~ {
     1..2
-    ok 1 - first {
+    ok 1 - first ___/# time=[0-9.]+(ms)?/~~~ {
         1..2
         ok 1 - true is ok
         ok 2 - doag is also okay
     }
 
-    ok 2 - second {
+    ok 2 - second ___/# time=[0-9.]+(ms)?/~~~ {
         ok 1 - but that is ok
         ok 2 - this passes
         1..2

diff --git a/test/test/bailout--bail.tap b/test/test/bailout--bail.tap
@@ -5,15 +5,15 @@ TAP version 13
         1..2
         ok 1 - true is ok
         ok 2 - doag is also okay
-    ok 1 - first
+    ok 1 - first ___/# time=[0-9.]+(ms)?/~~~
 
     # Subtest: second
         ok 1 - but that is ok
         ok 2 - this passes
         1..2
-    ok 2 - second
+    ok 2 - second ___/# time=[0-9.]+(ms)?/~~~
 
-ok 1 - nesting
+ok 1 - nesting ___/# time=[0-9.]+(ms)?/~~~
 
 ok 2 - this passes
 not ok 3 - this fails