Mercurial > hg
comparison tests/run-tests.py @ 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.
author | Pierre-Yves David <pierre-yves.david@fb.com> |
---|---|
date | Thu, 07 May 2015 23:34:58 -0700 |
parents | f66fc374d2d7 |
children | bf84ab53c2fd |
comparison
equal
deleted
inserted
replaced
25096:081b08e4ea13 | 25097:a4fce7905721 |
---|---|
1198 # unittest implementation. It is very similar to failed. It may make | 1198 # unittest implementation. It is very similar to failed. It may make |
1199 # sense to map it into fail some day. | 1199 # sense to map it into fail some day. |
1200 self.warned = [] | 1200 self.warned = [] |
1201 | 1201 |
1202 self.times = [] | 1202 self.times = [] |
1203 self._firststarttime = None | |
1203 # Data stored for the benefit of generating xunit reports. | 1204 # Data stored for the benefit of generating xunit reports. |
1204 self.successes = [] | 1205 self.successes = [] |
1205 self.faildata = {} | 1206 self.faildata = {} |
1206 | 1207 |
1207 def addFailure(self, test, reason): | 1208 def addFailure(self, test, reason): |
1322 # os.times module computes the user time and system time spent by | 1323 # os.times module computes the user time and system time spent by |
1323 # child's processes along with real elapsed time taken by a process. | 1324 # child's processes along with real elapsed time taken by a process. |
1324 # This module has one limitation. It can only work for Linux user | 1325 # This module has one limitation. It can only work for Linux user |
1325 # and not for Windows. | 1326 # and not for Windows. |
1326 test.started = os.times() | 1327 test.started = os.times() |
1328 if self._firststarttime is None: # thread racy but irrelevant | |
1329 self._firststarttime = test.started[4] | |
1327 | 1330 |
1328 def stopTest(self, test, interrupted=False): | 1331 def stopTest(self, test, interrupted=False): |
1329 super(TestResult, self).stopTest(test) | 1332 super(TestResult, self).stopTest(test) |
1330 | 1333 |
1331 test.stopped = os.times() | 1334 test.stopped = os.times() |
1332 | 1335 |
1333 starttime = test.started | 1336 starttime = test.started |
1334 endtime = test.stopped | 1337 endtime = test.stopped |
1338 origin = self._firststarttime | |
1335 self.times.append((test.name, | 1339 self.times.append((test.name, |
1336 endtime[2] - starttime[2], # user space CPU time | 1340 endtime[2] - starttime[2], # user space CPU time |
1337 endtime[3] - starttime[3], # sys space CPU time | 1341 endtime[3] - starttime[3], # sys space CPU time |
1338 endtime[4] - starttime[4], # real time | 1342 endtime[4] - starttime[4], # real time |
1343 starttime[4] - origin, # start date in run context | |
1344 endtime[4] - origin, # end date in run context | |
1339 )) | 1345 )) |
1340 | 1346 |
1341 if interrupted: | 1347 if interrupted: |
1342 with iolock: | 1348 with iolock: |
1343 self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % ( | 1349 self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % ( |
1568 for res, testcases in groups: | 1574 for res, testcases in groups: |
1569 for tc, __ in testcases: | 1575 for tc, __ in testcases: |
1570 tres = {'result': res, | 1576 tres = {'result': res, |
1571 'time': ('%0.3f' % timesd[tc.name][2]), | 1577 'time': ('%0.3f' % timesd[tc.name][2]), |
1572 'cuser': ('%0.3f' % timesd[tc.name][0]), | 1578 'cuser': ('%0.3f' % timesd[tc.name][0]), |
1573 'csys': ('%0.3f' % timesd[tc.name][1])} | 1579 'csys': ('%0.3f' % timesd[tc.name][1]), |
1580 'start': ('%0.3f' % timesd[tc.name][3]), | |
1581 'end': ('%0.3f' % timesd[tc.name][4])} | |
1574 outcome[tc.name] = tres | 1582 outcome[tc.name] = tres |
1575 | |
1576 jsonout = json.dumps(outcome, sort_keys=True, indent=4) | 1583 jsonout = json.dumps(outcome, sort_keys=True, indent=4) |
1577 fp.writelines(("testreport =", jsonout)) | 1584 fp.writelines(("testreport =", jsonout)) |
1578 finally: | 1585 finally: |
1579 fp.close() | 1586 fp.close() |
1580 | 1587 |