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.

25096:081b08e4ea13

        # unittest implementation. It is very similar to failed. It may make
        # sense to map it into fail some day.
        self.warned = []

        self.times = []
        # Data stored for the benefit of generating xunit reports.
        self.successes = []
        self.faildata = {}

    def addFailure(self, test, reason):

        # os.times module computes the user time and system time spent by
        # child's processes along with real elapsed time taken by a process.
        # This module has one limitation. It can only work for Linux user
        # and not for Windows.
        test.started = os.times()

    def stopTest(self, test, interrupted=False):
        super(TestResult, self).stopTest(test)

        test.stopped = os.times()

        starttime = test.started
        endtime = test.stopped
        self.times.append((test.name,
                           endtime[2] - starttime[2], # user space CPU time
                           endtime[3] - starttime[3], # sys  space CPU time
                           endtime[4] - starttime[4], # real time
                           ))

        if interrupted:
            with iolock:
                self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % (

                    for res, testcases in groups:
                        for tc, __ in testcases:
                            tres = {'result': res,
                                    'time': ('%0.3f' % timesd[tc.name][2]),
                                    'cuser': ('%0.3f' % timesd[tc.name][0]),
                                    'csys': ('%0.3f' % timesd[tc.name][1])}
                            outcome[tc.name] = tres

                    jsonout = json.dumps(outcome, sort_keys=True, indent=4)
                    fp.writelines(("testreport =", jsonout))
                finally:
                    fp.close()

25097:a4fce7905721

        # unittest implementation. It is very similar to failed. It may make
        # sense to map it into fail some day.
        self.warned = []

        self.times = []
        self._firststarttime =  None
        # Data stored for the benefit of generating xunit reports.
        self.successes = []
        self.faildata = {}

    def addFailure(self, test, reason):

        # os.times module computes the user time and system time spent by
        # child's processes along with real elapsed time taken by a process.
        # This module has one limitation. It can only work for Linux user
        # and not for Windows.
        test.started = os.times()
        if self._firststarttime is None: # thread racy but irrelevant
            self._firststarttime = test.started[4]

    def stopTest(self, test, interrupted=False):
        super(TestResult, self).stopTest(test)

        test.stopped = os.times()

        starttime = test.started
        endtime = test.stopped
        origin = self._firststarttime
        self.times.append((test.name,
                           endtime[2] - starttime[2], # user space CPU time
                           endtime[3] - starttime[3], # sys  space CPU time
                           endtime[4] - starttime[4], # real time
                           starttime[4] - origin, # start date in run context
                           endtime[4] - origin, # end date in run context
                           ))

        if interrupted:
            with iolock:
                self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % (

                    for res, testcases in groups:
                        for tc, __ in testcases:
                            tres = {'result': res,
                                    'time': ('%0.3f' % timesd[tc.name][2]),
                                    'cuser': ('%0.3f' % timesd[tc.name][0]),
                                    'csys': ('%0.3f' % timesd[tc.name][1]),
                                    'start': ('%0.3f' % timesd[tc.name][3]),
                                    'end': ('%0.3f' % timesd[tc.name][4])}
                            outcome[tc.name] = tres
                    jsonout = json.dumps(outcome, sort_keys=True, indent=4)
                    fp.writelines(("testreport =", jsonout))
                finally:
                    fp.close()