diff tests/test-run-tests.t @ 25097:a4fce7905721

run-tests: track start and end time of tests

We currently have information about how long each test took, but we have no data
about their actual scheduling. So we now track when a test started and stopped
(in the referential of the whole tests run) to expose this information.

The data is currently in the json only because the json output is meant to be
extensible. Later changeset will includes this data in the text output and we
will be happy to bikeshed its formating there.

Yes, "end" is actually just "start" + "time", but computing it an including it
in the output is simple, cheap and convenient.

--- a/tests/test-run-tests.t	Fri May 15 09:07:27 2015 -0400
+++ b/tests/test-run-tests.t	Thu May 07 23:34:58 2015 -0700
@@ -480,19 +480,25 @@
       "test-failure.t": [\{] (re)
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "failure", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }, ? (re)
       "test-skip.t": {
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "skip", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }, ? (re)
       "test-success.t": [\{] (re)
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "success", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }
   } (no-eol)
@@ -519,19 +525,25 @@
       "test-failure.t": [\{] (re)
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "success", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }, ? (re)
       "test-skip.t": {
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "skip", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }, ? (re)
       "test-success.t": [\{] (re)
           "csys": "\s*[\d\.]{4,5}", ? (re)
           "cuser": "\s*[\d\.]{4,5}", ? (re)
+          "end": "\s*[\d\.]{4,5}", ? (re)
           "result": "success", ? (re)
+          "start": "\s*[\d\.]{4,5}", ? (re)
           "time": "\s*[\d\.]{4,5}" (re)
       }
   } (no-eol)