Subject: Re: Drastic jump in the time required for the test suite

From: Johannes Schindelin <[email-masked]>
Date: Thu, 20 Oct 2016 12:50:32 +0200 (CEST)

Hi peff,

On Wed, 19 Oct 2016, Jeff King wrote:

> On Wed, Oct 19, 2016 at 10:32:12AM -0700, Junio C Hamano wrote:
> 
> > > Maybe we should start optimizing the tests...
> > 
> > Yup, two things that come to mind are to identify long ones and see if
> > each of them can be split into two halves that can be run in parallel,
> > and to go through the tests with fine toothed comb and remove the ones
> > that test exactly the same thing as another test.  The latter would be
> > very time consuming, though.
> 
> FWIW, I have made attempts at "split long ones into two" before, and
> didn't come up with much. There _are_ some tests that are much longer
> than others[1], but they are not longer than the whole suite takes to
> run. So running in slow-to-fast order means they start first, are run in
> parallel with the other tests, and the CPUs stay relatively full through
> the whole run.

That reflects my findings, too. I want to add that I found preciously
little difference between running slow-to-fast and running in numeric
order, so I gave up on optimizing on that front.

>     43.216765165329 t3404-rebase-interactive.sh
>     30.6568658351898 t3421-rebase-topology-linear.sh
>     27.92564702034 t9001-send-email.sh
>     15.5906939506531 t9500-gitweb-standalone-no-errors.sh
>     15.4882569313049 t6030-bisect-porcelain.sh
>     14.487174987793 t7610-mergetool.sh
>     13.8276169300079 t3425-rebase-topology-merges.sh
>     12.7450480461121 t3426-rebase-submodule.sh
>     12.4915001392365 t3415-rebase-autosquash.sh
>     11.8122401237488 t5572-pull-submodule.sh

That looks very similar to what I found: t3404 on top, followed by t3421.

Further, I found that the Subversion tests (which run at the end) are so
close in their running time that running the tests in parallel with -j5
does not result in any noticeable improvement when reordered.

I guess I will have to bite into the sour apple and try to profile, say,
t3404 somehow, including all the shell scripting stuff, to identify where
exactly all that time is lost. My guess is that it boils down to
gazillions of calls to programs like expr.exe or merely subshells.

Ciao,
Dscho