Submitter | Anurag Goel |
---|---|
Date | June 18, 2014, 8:37 a.m. |
Message ID | <faa6469d11ddb4842169.1403080632@ubuntu.ubuntu-domain> |
Download | mbox | patch |
Permalink | /patch/5013/ |
State | Superseded |
Commit | 4ca4e15720223743bcdff42ce88c47675a94dcb8 |
Headers | show |
Comments
On Wed, Jun 18, 2014 at 2:07 PM, Anurag Goel <anurag.dsps@gmail.com> wrote: > # HG changeset patch > # User anuraggoel <anurag.dsps@gmail.com> > # Date 1403079999 -19800 > # Wed Jun 18 13:56:39 2014 +0530 > # Node ID faa6469d11ddb4842169be76fb8f83312e5e0359 > # Parent 4951b897118e18d3081f07b98a96c0a917d71a24 > run-tests: '--time' option provide more details to Linux users > > As our tests execute in child processes, this patch uses os.times() > module in replace of time.time() module to provide additional info like > user time and system time spent by child's processes along with real > ellapased > time taken by a process. > > There is one limitation of this patch. It can work only for Linux users > and not > for Windows. > > "os.times" module returns a 5-tuple of a floaing point numbers. > 1) User time > 2) System time > 3) Child's user time > 4) Child's system time > 5) Ellapsed real time > > On Windows, only the first two items are filled, the others are zero. > Therefore, below test case does not break on Windows but instead gives the > null value. > > diff -r 4951b897118e -r faa6469d11dd tests/run-tests.py > --- a/tests/run-tests.py Wed Jun 18 02:29:14 2014 +0530 > +++ b/tests/run-tests.py Wed Jun 18 13:56:39 2014 +0530 > @@ -1070,6 +1070,7 @@ > > self.times = [] > self._started = {} > + self._stopped = {} > > def addFailure(self, test, reason): > self.failures.append((test, reason)) > @@ -1159,17 +1160,23 @@ > def startTest(self, test): > super(TestResult, self).startTest(test) > > - self._started[test.name] = time.time() > + self._started[test.name] = os.times() > > def stopTest(self, test, interrupted=False): > super(TestResult, self).stopTest(test) > > - self.times.append((test.name, time.time() - self._started[ > test.name])) > + self._stopped[test.name] = os.times() > + self.times.append((test.name, self._stopped[test.name][2] - > + self._started[test.name][2], self._stopped[test.name][3] > - > + self._started[test.name][3], self._stopped[test.name][4] > - > + self._started[test.name][4])) > + > del self._started[test.name] > + del self._stopped[test.name] > > if interrupted: > self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % ( > - test.name, self.times[-1][1])) > + test.name, self.times[-1][3])) > > class TestSuite(unittest.TestSuite): > """Custom unitest TestSuite that knows how to execute Mercurial > tests.""" > @@ -1338,11 +1345,12 @@ > > def printtimes(self, times): > self.stream.writeln('# Producing time report') > - times.sort(key=lambda t: (t[1], t[0]), reverse=True) > - cols = '%7.3f %s' > - self.stream.writeln('%-7s %s' % ('Time', 'Test')) > - for test, timetaken in times: > - self.stream.writeln(cols % (timetaken, test)) > + times.sort(key=lambda t: (t[3])) > + cols = '%0.3f %7.3f %7.3f %s' > + self.stream.writeln('%-7s %-7s %-7s %s' % ('cuser', 'csys', > 'real', > + 'Test')) > + for test, cuser, csys, real in times: > + self.stream.writeln(cols % (cuser, csys, real, test)) > > class TestRunner(object): > """Holds context for executing tests. > diff -r 4951b897118e -r faa6469d11dd tests/test-run-tests.t > --- a/tests/test-run-tests.t Wed Jun 18 02:29:14 2014 +0530 > +++ b/tests/test-run-tests.t Wed Jun 18 13:56:39 2014 +0530 > @@ -19,6 +19,16 @@ > . > # Ran 1 tests, 0 skipped, 0 warned, 0 failed. > > +test for --time > +================== > + > + $ $TESTDIR/run-tests.py --with-hg=`which hg` --time > + . > + # Ran 1 tests, 0 skipped, 0 warned, 0 failed. > + # Producing time report > + cuser csys real Test > + * (glob) > * (glob) could be replace with the following line [\d.\s]{23} test-success.t (re) This one looks more precise. + > failing test > ================== > > I will wait to get more review on this patch before sending the next version of this patch.
On 06/18/2014 01:37 AM, Anurag Goel wrote: > # HG changeset patch > # User anuraggoel <anurag.dsps@gmail.com> > # Date 1403079999 -19800 > # Wed Jun 18 13:56:39 2014 +0530 > # Node ID faa6469d11ddb4842169be76fb8f83312e5e0359 > # Parent 4951b897118e18d3081f07b98a96c0a917d71a24 > run-tests: '--time' option provide more details to Linux users > > As our tests execute in child processes, this patch uses os.times() > module in replace of time.time() module to provide additional info like > user time and system time spent by child's processes along with real ellapased > time taken by a process. > > There is one limitation of this patch. It can work only for Linux users and not > for Windows. > > "os.times" module returns a 5-tuple of a floaing point numbers. > 1) User time > 2) System time > 3) Child's user time > 4) Child's system time > 5) Ellapsed real time > > On Windows, only the first two items are filled, the others are zero. > Therefore, below test case does not break on Windows but instead gives the > null value. > > diff -r 4951b897118e -r faa6469d11dd tests/run-tests.py > --- a/tests/run-tests.py Wed Jun 18 02:29:14 2014 +0530 > +++ b/tests/run-tests.py Wed Jun 18 13:56:39 2014 +0530 > @@ -1070,6 +1070,7 @@ > > self.times = [] > self._started = {} > + self._stopped = {} > > def addFailure(self, test, reason): > self.failures.append((test, reason)) > @@ -1159,17 +1160,23 @@ > def startTest(self, test): > super(TestResult, self).startTest(test) > > - self._started[test.name] = time.time() > + self._started[test.name] = os.times() You should document the new content type here (in a comment) > > def stopTest(self, test, interrupted=False): > super(TestResult, self).stopTest(test) > > - self.times.append((test.name, time.time() - self._started[test.name])) > + self._stopped[test.name] = os.times() > + self.times.append((test.name, self._stopped[test.name][2] - > + self._started[test.name][2], self._stopped[test.name][3] - > + self._started[test.name][3], self._stopped[test.name][4] - > + self._started[test.name][4])) > + 1. the indentation is wrong should be align with parents opening. 2. unreadale blob. Put stuff in intermediate variable. > del self._started[test.name] > + del self._stopped[test.name] suspicious indentation. > > if interrupted: > self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % ( > - test.name, self.times[-1][1])) > + test.name, self.times[-1][3])) > > class TestSuite(unittest.TestSuite): > """Custom unitest TestSuite that knows how to execute Mercurial tests.""" > @@ -1338,11 +1345,12 @@ > > def printtimes(self, times): > self.stream.writeln('# Producing time report') > - times.sort(key=lambda t: (t[1], t[0]), reverse=True) > - cols = '%7.3f %s' > - self.stream.writeln('%-7s %s' % ('Time', 'Test')) > - for test, timetaken in times: > - self.stream.writeln(cols % (timetaken, test)) > + times.sort(key=lambda t: (t[3])) > + cols = '%0.3f %7.3f %7.3f %s' > + self.stream.writeln('%-7s %-7s %-7s %s' % ('cuser', 'csys', 'real', > + 'Test')) > + for test, cuser, csys, real in times: > + self.stream.writeln(cols % (cuser, csys, real, test)) > > class TestRunner(object): > """Holds context for executing tests. > diff -r 4951b897118e -r faa6469d11dd tests/test-run-tests.t > --- a/tests/test-run-tests.t Wed Jun 18 02:29:14 2014 +0530 > +++ b/tests/test-run-tests.t Wed Jun 18 13:56:39 2014 +0530 > @@ -19,6 +19,16 @@ > . > # Ran 1 tests, 0 skipped, 0 warned, 0 failed. > > +test for --time > +================== > + > + $ $TESTDIR/run-tests.py --with-hg=`which hg` --time > + . > + # Ran 1 tests, 0 skipped, 0 warned, 0 failed. > + # Producing time report > + cuser csys real Test > + * (glob) The glob is far too wide. Please produce a more precise regular expression. You should also provides a test that check --time with --jobs
Patch
diff -r 4951b897118e -r faa6469d11dd tests/run-tests.py --- a/tests/run-tests.py Wed Jun 18 02:29:14 2014 +0530 +++ b/tests/run-tests.py Wed Jun 18 13:56:39 2014 +0530 @@ -1070,6 +1070,7 @@ self.times = [] self._started = {} + self._stopped = {} def addFailure(self, test, reason): self.failures.append((test, reason)) @@ -1159,17 +1160,23 @@ def startTest(self, test): super(TestResult, self).startTest(test) - self._started[test.name] = time.time() + self._started[test.name] = os.times() def stopTest(self, test, interrupted=False): super(TestResult, self).stopTest(test) - self.times.append((test.name, time.time() - self._started[test.name])) + self._stopped[test.name] = os.times() + self.times.append((test.name, self._stopped[test.name][2] - + self._started[test.name][2], self._stopped[test.name][3] - + self._started[test.name][3], self._stopped[test.name][4] - + self._started[test.name][4])) + del self._started[test.name] + del self._stopped[test.name] if interrupted: self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % ( - test.name, self.times[-1][1])) + test.name, self.times[-1][3])) class TestSuite(unittest.TestSuite): """Custom unitest TestSuite that knows how to execute Mercurial tests.""" @@ -1338,11 +1345,12 @@ def printtimes(self, times): self.stream.writeln('# Producing time report') - times.sort(key=lambda t: (t[1], t[0]), reverse=True) - cols = '%7.3f %s' - self.stream.writeln('%-7s %s' % ('Time', 'Test')) - for test, timetaken in times: - self.stream.writeln(cols % (timetaken, test)) + times.sort(key=lambda t: (t[3])) + cols = '%0.3f %7.3f %7.3f %s' + self.stream.writeln('%-7s %-7s %-7s %s' % ('cuser', 'csys', 'real', + 'Test')) + for test, cuser, csys, real in times: + self.stream.writeln(cols % (cuser, csys, real, test)) class TestRunner(object): """Holds context for executing tests. diff -r 4951b897118e -r faa6469d11dd tests/test-run-tests.t --- a/tests/test-run-tests.t Wed Jun 18 02:29:14 2014 +0530 +++ b/tests/test-run-tests.t Wed Jun 18 13:56:39 2014 +0530 @@ -19,6 +19,16 @@ . # Ran 1 tests, 0 skipped, 0 warned, 0 failed. +test for --time +================== + + $ $TESTDIR/run-tests.py --with-hg=`which hg` --time + . + # Ran 1 tests, 0 skipped, 0 warned, 0 failed. + # Producing time report + cuser csys real Test + * (glob) + failing test ==================