You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by Bhuvaneswaran A <bh...@collab.net> on 2009/10/26 10:20:27 UTC
[PATCH] Include milliseconds in test report
As discussed in this email thread [1], please find attached the patch to
include milliseconds in the time taken to execute each test.
[[
While running the test suite, even the milliseconds are accountable.
* build/run_tests.py
(_run_test): Include milliseconds while printing the time taken to
execute each test.
]]
[1]
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411327
--
Bhuvaneswaran A
CollabNet Software P Ltd. | www.collab.net
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411330
Re: [PATCH] Include milliseconds in test report
Posted by Bhuvaneswaran A <bh...@collab.net>.
On Mon, 2009-10-26 at 13:32 +0100, Branko Čibej wrote:
>
> > AFAIK, srrftime() does not seem to support milliseconds.
>
> [...] Oh duh! Sorry, I mixed up my modules. No, i don't think it makes
> sense to use datetime just for this. I'd do something like the
> following:
>
> elapsed_time = time.strftime('%H:%M:%S.%%03d',
> time.gmtime(test_time)) % \
> math.floor(0.5 + 1000 * math.modf(test_time)[0])
>
> and don't forget to "import math"
Thanks, Branko. Please find attached the revised patch using the methods
in math library.
[[
While running the test suite, even the milliseconds are accountable.
* build/run_tests.py
import math
(_run_test): Include milliseconds while printing the time taken to
execute each test.
]]
--
Bhuvaneswaran A
CollabNet Software P Ltd. | www.collab.net
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411372
Re: [PATCH] Include milliseconds in test report
Posted by Bhuvaneswaran A <bh...@collab.net>.
On Tue, 2009-10-27 at 04:37 +0100, Branko Čibej wrote:
> Bhuvaneswaran A wrote:
> > I guess so. We can verify once this change is deployed with
> > junit/hudson. Please find attached the revised patch, ditching time
> > library, but only using datetime library, similar to above suggestion.
> >
> > Can you please review the patch?
> > [[
> > While running the test suite, even the microseconds are accountable.
> >
> > * build/run_tests.py
> > import datetime
> > (_run_test): Include microseconds while printing the time taken to
> > execute each test. Use datetime library instead of time library.
> > ]]
> >
> > Thanks!
> >
>
> The patch is fine, please commit it. I ran the tests on my teensy laptop
> (with a RAMdisk) and got:
Thanks, Branko. Committed the patch in r40229.
--
Bhuvaneswaran A
CollabNet Software P Ltd. | www.collab.net
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411583
Re: [PATCH] Include milliseconds in test report
Posted by Branko Cibej <br...@xbc.nu>.
Bhuvaneswaran A wrote:
> On Mon, 2009-10-26 at 17:16 +0100, Branko Čibej wrote:
>
>> Eh, you have a point. Premature optimization blues. Pity it can't
>> format
>> microseconds directly, though ... but it appears to me that if we use
>> datetime, one can just do:
>>
>> import datetime
>> start_time = datetime.datetime.now()
>> # ...
>> elapsed_time = str(datetime.datetime.now() - start_time)
>>
>> that won't zero-pad the hours, and will print microseconds instead of
>> milliseconds; but surely that shouldn't be a problem as far as parsing
>> the time for JUnit is concerned, yes?
>>
>
> I guess so. We can verify once this change is deployed with
> junit/hudson. Please find attached the revised patch, ditching time
> library, but only using datetime library, similar to above suggestion.
>
> Can you please review the patch?
> [[
> While running the test suite, even the microseconds are accountable.
>
> * build/run_tests.py
> import datetime
> (_run_test): Include microseconds while printing the time taken to
> execute each test. Use datetime library instead of time library.
> ]]
>
> Thanks!
>
The patch is fine, please commit it. I ran the tests on my teensy laptop
(with a RAMdisk) and got:
real 31m22.361s
user 21m42.720s
sys 15m50.920s
Summing up the ELAPSED lines from tests.log yields:
00:31:21.28
So it would appear that we're calculating test duration correctly. If
the discrepancy between reality and what JUnit reports is bigger htan
this second or so, the problem is clearly in the log file parser, not in
the elapsed time calculation.
-- Brane
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411581
Re: [PATCH] Include milliseconds in test report
Posted by Bhuvaneswaran A <bh...@collab.net>.
On Mon, 2009-10-26 at 17:16 +0100, Branko Čibej wrote:
>
> Eh, you have a point. Premature optimization blues. Pity it can't
> format
> microseconds directly, though ... but it appears to me that if we use
> datetime, one can just do:
>
> import datetime
> start_time = datetime.datetime.now()
> # ...
> elapsed_time = str(datetime.datetime.now() - start_time)
>
> that won't zero-pad the hours, and will print microseconds instead of
> milliseconds; but surely that shouldn't be a problem as far as parsing
> the time for JUnit is concerned, yes?
I guess so. We can verify once this change is deployed with
junit/hudson. Please find attached the revised patch, ditching time
library, but only using datetime library, similar to above suggestion.
Can you please review the patch?
[[
While running the test suite, even the microseconds are accountable.
* build/run_tests.py
import datetime
(_run_test): Include microseconds while printing the time taken to
execute each test. Use datetime library instead of time library.
]]
Thanks!
--
Bhuvaneswaran A
CollabNet Software P Ltd. | www.collab.net
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411566
Re: [PATCH] Include milliseconds in test report
Posted by Branko Cibej <br...@xbc.nu>.
Greg Stein wrote:
> On Mon, Oct 26, 2009 at 08:32, Branko Cibej <br...@xbc.nu> wrote:
>
>>> AFAIK, srrftime() does not seem to support milliseconds.
>>>
>> [...] Oh duh! Sorry, I mixed up my modules. No, i don't think it makes
>> sense to use datetime just for this. I'd do something like the following:
>>
>> elapsed_time = time.strftime('%H:%M:%S.%%03d', time.gmtime(test_time)) % \
>> math.floor(0.5 + 1000 * math.modf(test_time)[0])
>>
>> and don't forget to "import math"
>>
>
> What? Something wrong with datetime, such that the math module is
> better? If you gotta import one, then why not the one related to what
> you're trying to do?
>
Eh, you have a point. Premature optimization blues. Pity it can't format
microseconds directly, though ... but it appears to me that if we use
datetime, one can just do:
import datetime
start_time = datetime.datetime.now()
# ...
elapsed_time = str(datetime.datetime.now() - start_time)
that won't zero-pad the hours, and will print microseconds instead of
milliseconds; but surely that shouldn't be a problem as far as parsing
the time for JUnit is concerned, yes?
-- Brane
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411430
Re: [PATCH] Include milliseconds in test report
Posted by Greg Stein <gs...@gmail.com>.
On Mon, Oct 26, 2009 at 08:32, Branko Cibej <br...@xbc.nu> wrote:
> Bhuvaneswaran A wrote:
>> On Mon, 2009-10-26 at 11:38 +0100, Branko Čibej wrote:
>>
>>> "As discussed", yes; but I don't believe this will account for the
>>> discrepancy between wall clock time and reported test execution time,
>>> also "as discussed". :)
>>>
>>
>> Yes; refer to my reply to another email thread for reasons that is
>> contributing to this discrepancy.
>>
>>
>>>> Index: build/run_tests.py
>>>> =======================================
>>>> --- build/run_tests.py (revision 40220)
>>>> +++ build/run_tests.py (working copy)
>>>> @@ -270,8 +270,14 @@
>>>> log.write('FAIL: %s: Unknown test failure.\n' % progbase)
>>>> # Log the elapsed time.
>>>> - elapsed_time = time.strftime('%H:%M:%S',
>>>> - time.gmtime(time.time() - start_time))
>>>> + test_time = time.time() - start_time
>>>> + elapsed_time = time.strftime('%H:%M:%S', time.gmtime(test_time))
>>>> +
>>>> + # certain system clock may not provide fractions of second
>>>> + if str(test_time).find('.') == -1:
>>>> + elapsed_time += '.00'
>>>> + else:
>>>> + elapsed_time += '.' + str(test_time).split('.')[1]
>>>> log.write('END: %s\n' % progbase)
>>>> log.write('ELAPSED: %s %s\n' % (progbase, elapsed_time))
>>>> log.write('\n')
>>>>
>>> Uh. Why don't you just format in the milliseconds in strftime? The
>>> Python documentation is your friend. Who cares if the system clock
>>> isn't
>>> precise enough -- you'll just get the zeros there from strftime
>>> instead.
>>> (And note that you need three digits, not two, to correctly represent
>>> milliseconds.)
>>>
>>
>> AFAIK, srrftime() does not seem to support milliseconds.
>
> [...] Oh duh! Sorry, I mixed up my modules. No, i don't think it makes
> sense to use datetime just for this. I'd do something like the following:
>
> elapsed_time = time.strftime('%H:%M:%S.%%03d', time.gmtime(test_time)) % \
> math.floor(0.5 + 1000 * math.modf(test_time)[0])
>
> and don't forget to "import math"
What? Something wrong with datetime, such that the math module is
better? If you gotta import one, then why not the one related to what
you're trying to do?
Cheers,
-g
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411414
Re: [PATCH] Include milliseconds in test report
Posted by Branko Cibej <br...@xbc.nu>.
Bhuvaneswaran A wrote:
> On Mon, 2009-10-26 at 11:38 +0100, Branko Čibej wrote:
>
>> "As discussed", yes; but I don't believe this will account for the
>> discrepancy between wall clock time and reported test execution time,
>> also "as discussed". :)
>>
>
> Yes; refer to my reply to another email thread for reasons that is
> contributing to this discrepancy.
>
>
>>> Index: build/run_tests.py
>>> =======================================
>>> --- build/run_tests.py (revision 40220)
>>> +++ build/run_tests.py (working copy)
>>> @@ -270,8 +270,14 @@
>>> log.write('FAIL: %s: Unknown test failure.\n' % progbase)
>>> # Log the elapsed time.
>>> - elapsed_time = time.strftime('%H:%M:%S',
>>> - time.gmtime(time.time() - start_time))
>>> + test_time = time.time() - start_time
>>> + elapsed_time = time.strftime('%H:%M:%S', time.gmtime(test_time))
>>> +
>>> + # certain system clock may not provide fractions of second
>>> + if str(test_time).find('.') == -1:
>>> + elapsed_time += '.00'
>>> + else:
>>> + elapsed_time += '.' + str(test_time).split('.')[1]
>>> log.write('END: %s\n' % progbase)
>>> log.write('ELAPSED: %s %s\n' % (progbase, elapsed_time))
>>> log.write('\n')
>>>
>> Uh. Why don't you just format in the milliseconds in strftime? The
>> Python documentation is your friend. Who cares if the system clock
>> isn't
>> precise enough -- you'll just get the zeros there from strftime
>> instead.
>> (And note that you need three digits, not two, to correctly represent
>> milliseconds.)
>>
>
> AFAIK, srrftime() does not seem to support milliseconds.
[...] Oh duh! Sorry, I mixed up my modules. No, i don't think it makes
sense to use datetime just for this. I'd do something like the following:
elapsed_time = time.strftime('%H:%M:%S.%%03d', time.gmtime(test_time)) % \
math.floor(0.5 + 1000 * math.modf(test_time)[0])
and don't forget to "import math"
-- Brane
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411367
Re: [PATCH] Include milliseconds in test report
Posted by Bhuvaneswaran A <bh...@collab.net>.
On Mon, 2009-10-26 at 11:38 +0100, Branko Čibej wrote:
>
> "As discussed", yes; but I don't believe this will account for the
> discrepancy between wall clock time and reported test execution time,
> also "as discussed". :)
Yes; refer to my reply to another email thread for reasons that is
contributing to this discrepancy.
> > Index: build/run_tests.py
> > =======================================
> > --- build/run_tests.py (revision 40220)
> > +++ build/run_tests.py (working copy)
> > @@ -270,8 +270,14 @@
> > log.write('FAIL: %s: Unknown test failure.\n' % progbase)
> > # Log the elapsed time.
> > - elapsed_time = time.strftime('%H:%M:%S',
> > - time.gmtime(time.time() - start_time))
> > + test_time = time.time() - start_time
> > + elapsed_time = time.strftime('%H:%M:%S', time.gmtime(test_time))
> > +
> > + # certain system clock may not provide fractions of second
> > + if str(test_time).find('.') == -1:
> > + elapsed_time += '.00'
> > + else:
> > + elapsed_time += '.' + str(test_time).split('.')[1]
> > log.write('END: %s\n' % progbase)
> > log.write('ELAPSED: %s %s\n' % (progbase, elapsed_time))
> > log.write('\n')
>
> Uh. Why don't you just format in the milliseconds in strftime? The
> Python documentation is your friend. Who cares if the system clock
> isn't
> precise enough -- you'll just get the zeros there from strftime
> instead.
> (And note that you need three digits, not two, to correctly represent
> milliseconds.)
AFAIK, srrftime() does not seem to support milliseconds. However, as per
document, starting v2.6 the microsecond format '%f' is supported. Our
code should be compatible with v2.4, right? Moreover, I could use
datetime.strftime() method to print microseconds using '%f' format (in
v2.6 release), but it does not work the same way using time.strftime()
method.
http://docs.python.org/library/datetime.html
That said, I am able to do these check using combination of both
datetime and time modules, something like this:
In [3]: start_time = datetime.datetime.now()
In [4]: end_time = datetime.datetime.now()
In [5]: delta = end_time - start_time
In [6]: elapsed = time.strftime('%H:%M:%S', time.gmtime(delta.seconds))
In [7]: elapsed += '.' + str(delta.microseconds/1000)
In [8]: elapsed
Out[8]: '00:00:09.256'
May i go for it?
--
Bhuvaneswaran A
CollabNet Software P Ltd. | www.collab.net
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411353
Re: [PATCH] Include milliseconds in test report
Posted by Branko Cibej <br...@xbc.nu>.
Bhuvaneswaran A wrote:
> As discussed in this email thread [1], please find attached the patch to
> include milliseconds in the time taken to execute each test.
>
> [[
> While running the test suite, even the milliseconds are accountable.
>
> * build/run_tests.py
> (_run_test): Include milliseconds while printing the time taken to
> execute each test.
> ]]
"As discussed", yes; but I don't believe this will account for the
discrepancy between wall clock time and reported test execution time,
also "as discussed". :)
> Index: build/run_tests.py
> =======================================
> --- build/run_tests.py (revision 40220)
> +++ build/run_tests.py (working copy)
> @@ -270,8 +270,14 @@
> log.write('FAIL: %s: Unknown test failure.\n' % progbase)
> # Log the elapsed time.
> - elapsed_time = time.strftime('%H:%M:%S',
> - time.gmtime(time.time() - start_time))
> + test_time = time.time() - start_time
> + elapsed_time = time.strftime('%H:%M:%S', time.gmtime(test_time))
> +
> + # certain system clock may not provide fractions of second
> + if str(test_time).find('.') == -1:
> + elapsed_time += '.00'
> + else:
> + elapsed_time += '.' + str(test_time).split('.')[1]
> log.write('END: %s\n' % progbase)
> log.write('ELAPSED: %s %s\n' % (progbase, elapsed_time))
> log.write('\n')
Uh. Why don't you just format in the milliseconds in strftime? The
Python documentation is your friend. Who cares if the system clock isn't
precise enough -- you'll just get the zeros there from strftime instead.
(And note that you need three digits, not two, to correctly represent
milliseconds.)
-- Brane
------------------------------------------------------
http://subversion.tigris.org/ds/viewMessage.do?dsForumId=462&dsMessageId=2411332