[PATCH] run-test: '--time' option provide more details to user

Gregory Szorc gregory.szorc at gmail.com
Mon May 26 19:03:34 UTC 2014


On 5/24/2014 12:10 PM, Anurag Goel wrote:
> # HG changeset patch
> # User anuraggoel <anurag.dsps at gmail.com>
> # Date 1400958116 -19800
> #      Sun May 25 00:31:56 2014 +0530
> # Node ID 0c6ee6403d787f8eb08fe01550f2e9e0aa637c26
> # Parent  883e268cb860c0ea2eb0faa94114e11c3a4a3893
> run-test: '--time' option provide more details to user
> 
> 'time.time()' module can only be used to calculate 'real' time taken by a
> process. Therefore, I switched it to 'os.times()' module which helps in
> getting additional info like "Total number of CPU-seconds that the process
> spent in kernel mode" and "Total number of CPU-seconds that the process spent
> in user mode".
> 
> diff -r 883e268cb860 -r 0c6ee6403d78 tests/run-tests.py
> --- a/tests/run-tests.py	Wed Apr 30 18:40:20 2014 -0700
> +++ b/tests/run-tests.py	Sun May 25 00:31:56 2014 +0530
> @@ -551,11 +551,11 @@
>  
>  def outputtimes(options):
>      vlog('# Producing time report')
> -    times.sort(key=lambda t: (t[1], t[0]), reverse=True)
> -    cols = '%7.3f   %s'
> -    print '\n%-7s   %s' % ('Time', 'Test')
> -    for test, timetaken in times:
> -        print cols % (timetaken, test)
> +    times.sort(key=lambda t: (t[2]))
> +    cols = '%0.3f %7.3f %7.3f  %s'
> +    print '\n%-7s %-7s %-7s  %s' % ('user', 'sys', 'real', 'Test')
> +    for user, sys, real, test in times:
> +        print cols % (user, sys, real, test)
>  
>  def outputcoverage(options):
>  
> @@ -990,15 +990,16 @@
>      env = createenv(options, testtmp, threadtmp, port)
>      createhgrc(env['HGRCPATH'], options)
>  
> -    starttime = time.time()
> +    starttime = os.times()
>      try:
>          ret, out = runner(testpath, testtmp, options, replacements, env)
>      except KeyboardInterrupt:
>          endtime = time.time()
>          log('INTERRUPTED: %s (after %d seconds)' % (test, endtime - starttime))
>          raise
> -    endtime = time.time()
> -    times.append((test, endtime - starttime))
> +    endtime = os.times()
> +    times.append((endtime[0] - starttime[0], endtime[1] - starttime[1],
> +                endtime[4] - starttime[4], test))
>      vlog("# Ret was:", ret)
>  
>      killdaemons(env['DAEMON_PIDS'])

Only the first 2 elements of os.times() are available on Windows.
Therefore this patch does not properly report wall time (os.times()[4])
on Windows and thus regresses behavior. Also, this patch has been bit
rotted by run-tests.py refactoring. Finally, test time recording occurs
in the parent process/thread whereas tests execute in child processes.
This patch doesn't measure what you think it is measuring.

I like the intention, but this patch isn't acceptable.



More information about the Mercurial-devel mailing list