Re: [PATCH] test-lib: add ability to cap the runtime of tests

From: Ramsay Jones <ramsay@ramsayjones.plus.com>
Date: Jun 8, 2017, 00:59 UTC
Message-ID: <3ae7243b-93f9-d7ba-0e3f-d0b3388d57ac@ramsayjones.plus.com>
In-Reply-To: <20170607102448.bpgxce4kduzxf7a2@sigill.intra.peff.net>

On 07/06/17 11:24, Jeff King wrote:

> On Mon, Jun 05, 2017 at 10:55:42AM +0900, Junio C Hamano wrote:
> 
> If you use "prove", it already records this information, and it can
> print it with "--timer".

Yes I have

    DEFAULT_TEST_TARGET=prove
    GIT_PROVE_OPTS='--timer'

in my config.mak and run the test: 'make test >test-out 2>&1'.

> I don't use that myself, though. What's much more interesting (but which
> I haven't found a way to get prove to do out-of-the-box) is to show the
> longest tests after the fact.

So, I have a perl script that can give me that info, like so:

On Linux, (current master branch), the ten slowest tests:

$ ./test-times.pl -n 10 test-out
   1   22.269s   t9001-send-email.sh
   2   15.222s   t7063-status-untracked-cache.sh
   3   10.965s   t9500-gitweb-standalone-no-errors.sh
   4    9.978s   t3404-rebase-interactive.sh
   5    9.270s   t3421-rebase-topology-linear.sh
   6    8.099s   t0027-auto-crlf.sh
   7    6.056s   t7112-reset-submodule.sh
   8    5.937s   t7610-mergetool.sh
   9    5.711s   t5572-pull-submodule.sh
  10    5.229s   t6030-bisect-porcelain.sh
$

... and those taking 10s or more:

$ ./test-times.pl -t 10 test-out
   1   22.269s   t9001-send-email.sh
   2   15.222s   t7063-status-untracked-cache.sh
   3   10.965s   t9500-gitweb-standalone-no-errors.sh
$

However, on cygwin (v2.13.0 test output file), the ten slowest:

$ ./test-times.pl -n 10 test-out
   1  385.057s   t3404-rebase-interactive.sh
   2  339.694s   t3421-rebase-topology-linear.sh
   3  224.854s   t7610-mergetool.sh
   4  211.230s   t6030-bisect-porcelain.sh
   5  180.297s   t3425-rebase-topology-merges.sh
   6  179.446s   t3903-stash.sh
   7  177.600s   t9001-send-email.sh
   8  175.278s   t5572-pull-submodule.sh
   9  160.422s   t2013-checkout-submodule.sh
  10  158.615s   t1013-read-tree-submodule.sh
$

... and (some of) those taking 10s or more:

$ ./test-times.pl -t 10 test-out
   1  385.057s   t3404-rebase-interactive.sh
   2  339.694s   t3421-rebase-topology-linear.sh
   3  224.854s   t7610-mergetool.sh
   4  211.230s   t6030-bisect-porcelain.sh

...

 175   10.389s   t4300-merge-tree.sh
 176   10.324s   t4213-log-tabexpand.sh
 177   10.143s   t3034-merge-recursive-rename-options.sh
 178   10.108s   t1410-reflog.sh
$

[On linux a complete run is about 400s and on cygwin about 3hours!]

ATB, Ramsay Jones