[PATCH] travis-ci: build Git during the 'script' phase

[PATCH] travis-ci: build Git during the 'script' phase

[SZEDER Gábor]

Ever since we started building and testing Git on Travis CI (522354d70
(Add Travis CI support, 2015-11-27)), we build Git in the
'before_script' phase and run the test suite in the 'script' phase
(except in the later introduced 32 bit Linux and Windows build jobs,
where we build in the 'script' phase').

Contrarily, the Travis CI practice is to build and test in the
'script' phase; indeed Travis CI's default build command for the
'script' phase of C/C++ projects is:

  ./configure && make && make test

The reason why Travis CI does it this way and why it's a better
approach than ours lies in how unsuccessful build jobs are
categorized.  After something went wrong in a build job, its state can
be:

  - 'failed', if a command in the 'script' phase returned an error.
    This is indicated by a red 'X' on the Travis CI web interface.

  - 'errored', if a command in the 'before_install', 'install', or
    'before_script' phase returned an error, or the build job exceeded
    the time limit.  This is shown as a red '!' on the web interface.

This makes it easier, both for humans looking at the Travis CI web
interface and for automated tools querying the Travis CI API, to
decide when an unsuccessful build is our responsibility requiring
human attention, i.e. when a build job 'failed' because of a compiler
error or a test failure, and when it's caused by something beyond our
control and might be fixed by restarting the build job, e.g. when a
build job 'errored' because a dependency couldn't be installed due to
a temporary network error or because the OSX build job exceeded its
time limit.

The drawback of building Git in the 'before_script' phase is that one
has to check the trace log of all 'errored' build jobs, too, to see
what caused the error, as it might have been caused by a compiler
error.  This requires additional clicks and page loads on the web
interface and additional complexity and API requests in automated
tools.

Therefore, move building Git from the 'before_script' phase to the
'script' phase, updating the script's name accordingly as well.
'ci/run-builds.sh' now becomes basically empty, remove it.  Several of
our build job configurations override our default 'before_script' to
do nothing; with this change our default 'before_script' won't do
anything, either, so remove those overriding directives as well.

Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
---

A verbose commit message for such a change... but I don't know why we
started with building Git in the 'before_script' phase.  522354d70
doesn't tell, and I couldn't find anything relevant in the mailing list
archives.  Whatever the reasons might have been, I think the above
justifies the change.

Should go on top of 'sg/travis-check-untracked' in 'next'.

 .travis.yml                                 | 7 +------
 ci/{run-tests.sh => run-build-and-tests.sh} | 4 +++-
 ci/run-build.sh                             | 8 --------
 3 files changed, 4 insertions(+), 15 deletions(-)
 rename ci/{run-tests.sh => run-build-and-tests.sh} (80%)
 delete mode 100755 ci/run-build.sh

diff --git a/.travis.yml b/.travis.yml
index 4684b3f4f..5f5ee4f3b 100644
--- a/.travis.yml
+++ b/.travis.yml
@@ -33,7 +33,6 @@ matrix:
       compiler:
       addons:
       before_install:
-      before_script:
       script:
         - >
           test "$TRAVIS_REPO_SLUG" != "git/git" ||
@@ -46,7 +45,6 @@ matrix:
       services:
         - docker
       before_install:
-      before_script:
       script: ci/run-linux32-docker.sh
     - env: jobname=StaticAnalysis
       os: linux
@@ -56,7 +54,6 @@ matrix:
           packages:
           - coccinelle
       before_install:
-      before_script:
       script: ci/run-static-analysis.sh
       after_failure:
     - env: jobname=Documentation
@@ -68,13 +65,11 @@ matrix:
           - asciidoc
           - xmlto
       before_install:
-      before_script:
       script: ci/test-documentation.sh
       after_failure:
 
 before_install: ci/install-dependencies.sh
-before_script: ci/run-build.sh
-script: ci/run-tests.sh
+script: ci/run-build-and-tests.sh
 after_failure: ci/print-test-failures.sh
 
 notifications:
diff --git a/ci/run-tests.sh b/ci/run-build-and-tests.sh
similarity index 80%
rename from ci/run-tests.sh
rename to ci/run-build-and-tests.sh
index 22355f009..d3a094603 100755
--- a/ci/run-tests.sh
+++ b/ci/run-build-and-tests.sh
@@ -1,11 +1,13 @@
 #!/bin/sh
 #
-# Test Git
+# Build and test Git
 #
 
 . ${0%/*}/lib-travisci.sh
 
 ln -s $HOME/travis-cache/.prove t/.prove
+
+make --jobs=2
 make --quiet test
 
 check_unignored_build_artifacts
diff --git a/ci/run-build.sh b/ci/run-build.sh
deleted file mode 100755
index 4f940d103..000000000
--- a/ci/run-build.sh
+++ /dev/null
@@ -1,8 +0,0 @@
-#!/bin/sh
-#
-# Build Git
-#
-
-. ${0%/*}/lib-travisci.sh
-
-make --jobs=2
-- 
2.16.0.rc1.67.g706959270

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Junio C Hamano]

SZEDER Gábor <szeder.dev@gmail.com> writes:

> The reason why Travis CI does it this way and why it's a better
> approach than ours lies in how unsuccessful build jobs are
> categorized.  ...
> ...
> This makes it easier, both for humans looking at the Travis CI web
> interface and for automated tools querying the Travis CI API,...
> ...
> A verbose commit message for such a change... but I don't know why we
> started with building Git in the 'before_script' phase.

Thanks for writing it up clearly.  TBH, I didn't even realize that
there were meaningful distinctions between the two cases after
seeing that sometimes our tests were failing and sometimes erroring
;-)

> Should go on top of 'sg/travis-check-untracked' in 'next'.

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Lars Schneider]

> On 08 Jan 2018, at 23:07, Junio C Hamano <gitster@pobox.com> wrote:
> 
> SZEDER Gábor <szeder.dev@gmail.com> writes:
> 
>> The reason why Travis CI does it this way and why it's a better
>> approach than ours lies in how unsuccessful build jobs are
>> categorized.  ...
>> ...
>> This makes it easier, both for humans looking at the Travis CI web
>> interface and for automated tools querying the Travis CI API,...
>> ...
>> A verbose commit message for such a change... but I don't know why we
>> started with building Git in the 'before_script' phase.
> 
> Thanks for writing it up clearly.  TBH, I didn't even realize that
> there were meaningful distinctions between the two cases after
> seeing that sometimes our tests were failing and sometimes erroring
> ;-)

I understand the reasons for the proposed patch. However, I did this 
intentionally back then. Here is my reason:

If `make` is successful, then I am not interested in its output.
Look at this run: https://travis-ci.org/szeder/git/jobs/324271623

You have to scroll down 1,406 lines to get to the test result 
output (this is usually the interesting part).

If this is a valid argument for you, would it be an option to
pipe the verbose `make` output to a file and only print it in case
of error (we do something similar for the tests already).

- Lars

Re: [PATCH] travis-ci: build Git during the 'script' phase

[SZEDER Gábor]

On Mon, Jan 8, 2018 at 11:38 PM, Lars Schneider
<larsxschneider@gmail.com> wrote:
>
>> On 08 Jan 2018, at 23:07, Junio C Hamano <gitster@pobox.com> wrote:
>>
>> SZEDER Gábor <szeder.dev@gmail.com> writes:
>>
>>> The reason why Travis CI does it this way and why it's a better
>>> approach than ours lies in how unsuccessful build jobs are
>>> categorized.  ...
>>> ...
>>> This makes it easier, both for humans looking at the Travis CI web
>>> interface and for automated tools querying the Travis CI API,...
>>> ...
>>> A verbose commit message for such a change... but I don't know why we
>>> started with building Git in the 'before_script' phase.
>>
>> Thanks for writing it up clearly.  TBH, I didn't even realize that
>> there were meaningful distinctions between the two cases after
>> seeing that sometimes our tests were failing and sometimes erroring
>> ;-)
>
> I understand the reasons for the proposed patch. However, I did this
> intentionally back then. Here is my reason:
>
> If `make` is successful, then I am not interested in its output.

If 'prove' is successful, then I'm not interested in its output ;)

> Look at this run: https://travis-ci.org/szeder/git/jobs/324271623
>
> You have to scroll down 1,406 lines to get to the test result
> output (this is usually the interesting part).

That's the just beginning of a looong list of executed test scripts in
seemingly pseudo-random order.  IMHO that's very rarely the interesting
part; I, for one, am only interested in that list in exceptional cases,
e.g. while tweaking the build dependencies or the 'prove --state=...'
options.

These are the really interesting parts of the build job's output, the
parts that do matter most of the time:

  # compiler error
  https://travis-ci.org/git/git/jobs/325252417#L1766
  # which tests failed
  https://travis-ci.org/git/git/jobs/315658238#L2247
  # stray build artifacts
  https://travis-ci.org/szeder/git/jobs/323531220#L2236
  # (no example logs for erroring while installing dependencies, OSX
  # timeout, etc.)

Note that these are all at the very end of the trace log, i.e. they are
easily accessible by one or two keystrokes (depending on whether the
keyboard has a dedicated 'End' key or requires an Fn combo), a vigorous
drag of the scrollbar, or a click on the "Scroll to end of log" circle
in the top right corner.

> If this is a valid argument for you,

I'm unconvinced :)

> would it be an option to
> pipe the verbose `make` output to a file and only print it in case
> of error (we do something similar for the tests already).

It's risky, because the build process would be completely silent for the
duration of building Git.  Travis CI considers a build 'errored' if it
doesn't produce any output for 10 minutes.  While building Git usually
takes much less time, transient slowdowns apparently do occur.

Gábor

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Jeff King]

On Fri, Jan 12, 2018 at 02:32:54PM +0100, SZEDER Gábor wrote:

> That's the just beginning of a looong list of executed test scripts in
> seemingly pseudo-random order.  IMHO that's very rarely the interesting
> part; I, for one, am only interested in that list in exceptional cases,
> e.g. while tweaking the build dependencies or the 'prove --state=...'
> options.

Aren't folds supposed to do this? I.e., record all the output but only
show it to the user if the command exited non-zero.

According to:

  https://blog.travis-ci.com/2013-05-22-improving-build-visibility-log-folds

they auto-fold individual commands _except_ the ones in the script
section. Is there a way to manually mark folds in the output?

Hmph. I could not find an answer from travis, but googling seems to turn
up that something like this would work:

diff --git a/ci/lib-travisci.sh b/ci/lib-travisci.sh
index 07f27c7270..8c830aa3c0 100755
--- a/ci/lib-travisci.sh
+++ b/ci/lib-travisci.sh
@@ -77,6 +77,23 @@ check_unignored_build_artifacts ()
 	}
 }
 
+fold () {
+	printf 'travis_fold:start:%s\r' "$1"
+}
+
+unfold () {
+	printf 'travis_fold:end:%s\r' "$1"
+}
+
+fold_cmd () {
+	local name=$1; shift
+	fold "$name"
+	"$@"
+	local ret=$?
+	unfold "$name"
+	return $ret
+}
+
 # Set 'exit on error' for all CI scripts to let the caller know that
 # something went wrong.
 # Set tracing executed commands, primarily setting environment variables
diff --git a/ci/run-build-and-tests.sh b/ci/run-build-and-tests.sh
index d3a094603f..12b2590230 100755
--- a/ci/run-build-and-tests.sh
+++ b/ci/run-build-and-tests.sh
@@ -7,8 +7,8 @@
 
 ln -s $HOME/travis-cache/.prove t/.prove
 
-make --jobs=2
-make --quiet test
+fold_cmd compile make --jobs=2
+fold_cmd test make --quiet test
 
 check_unignored_build_artifacts
 

I've queued a CI job to see if this actually works. :)

-Peff

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Jeff King]

On Sat, Jan 13, 2018 at 05:32:56AM -0500, Jeff King wrote:

> According to:
> 
>   https://blog.travis-ci.com/2013-05-22-improving-build-visibility-log-folds
> 
> they auto-fold individual commands _except_ the ones in the script
> section. Is there a way to manually mark folds in the output?
> 
> Hmph. I could not find an answer from travis, but googling seems to turn
> up that something like this would work:
> [...]
> I've queued a CI job to see if this actually works. :)

Indeed it does work:

  https://travis-ci.org/peff/git/jobs/328418291

The rest of the crufty output looks like "set -x" stuff. It might be
worth being less aggressive there.

I think there's also a similar feature to include timings for each fold,
which might be worth pursuing.

-Peff

Re: [PATCH] travis-ci: build Git during the 'script' phase

[SZEDER Gábor]

On Sat, Jan 13, 2018 at 11:32 AM, Jeff King <peff@peff.net> wrote:
> On Fri, Jan 12, 2018 at 02:32:54PM +0100, SZEDER Gábor wrote:
>
>> That's the just beginning of a looong list of executed test scripts in
>> seemingly pseudo-random order.  IMHO that's very rarely the interesting
>> part; I, for one, am only interested in that list in exceptional cases,
>> e.g. while tweaking the build dependencies or the 'prove --state=...'
>> options.
>
> Aren't folds supposed to do this? I.e., record all the output but only
> show it to the user if the command exited non-zero.
>
> According to:
>
>   https://blog.travis-ci.com/2013-05-22-improving-build-visibility-log-folds
>
> they auto-fold individual commands _except_ the ones in the script
> section. Is there a way to manually mark folds in the output?
>
> Hmph. I could not find an answer from travis, but googling seems to turn
> up that something like this would work:

Oh.  I did look for something like this in the Travis CI docs, found
nothing and then didn't bother with Google.  Rookie mistake, I know :)

But indeed, have a look at the raw trace log at:

  https://api.travis-ci.org/v3/job/328418291/log.txt

It starts with that "travis_fold:start:..." thing right away.

> diff --git a/ci/lib-travisci.sh b/ci/lib-travisci.sh
> index 07f27c7270..8c830aa3c0 100755
> --- a/ci/lib-travisci.sh
> +++ b/ci/lib-travisci.sh
> @@ -77,6 +77,23 @@ check_unignored_build_artifacts ()
>         }
>  }
>
> +fold () {
> +       printf 'travis_fold:start:%s\r' "$1"
> +}
> +
> +unfold () {
> +       printf 'travis_fold:end:%s\r' "$1"
> +}
> +
> +fold_cmd () {
> +       local name=$1; shift
> +       fold "$name"
> +       "$@"
> +       local ret=$?
> +       unfold "$name"
> +       return $ret
> +}

We don't have to fiddle with the return value, because we run (almost
all of) our build scripts with 'set -e', i.e. if the command fails then
the script will exit immediately.

> +
>  # Set 'exit on error' for all CI scripts to let the caller know that
>  # something went wrong.
>  # Set tracing executed commands, primarily setting environment variables
> diff --git a/ci/run-build-and-tests.sh b/ci/run-build-and-tests.sh
> index d3a094603f..12b2590230 100755
> --- a/ci/run-build-and-tests.sh
> +++ b/ci/run-build-and-tests.sh
> @@ -7,8 +7,8 @@
>
>  ln -s $HOME/travis-cache/.prove t/.prove
>
> -make --jobs=2
> -make --quiet test
> +fold_cmd compile make --jobs=2
> +fold_cmd test make --quiet test
>
>  check_unignored_build_artifacts
>
>
> I've queued a CI job to see if this actually works. :)
>
> -Peff

Re: [PATCH] travis-ci: build Git during the 'script' phase

[SZEDER Gábor]

On Sat, Jan 13, 2018 at 11:54 AM, Jeff King <peff@peff.net> wrote:
> I think there's also a similar feature to include timings for each fold,
> which might be worth pursuing.

If you look for 'travis_time' in the raw log, you'll find lines like
these:

  travis_time:start:01ccbe40
  $ some-command
  ... and its output ...
  travis_time:end:01ccbe40:start=1515840453305552968,finish=1515840471960386859,duration=18654833891

So it seems doable, but we'll have to do the timekeeping ourselves.
Running 'time $cmd' is much easier, but that time won't be displayed
next to the folds, of course.
Do we really care that much?


Gábor

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Jeff King]

On Sun, Jan 14, 2018 at 11:37:07AM +0100, SZEDER Gábor wrote:

> > +fold_cmd () {
> > +       local name=$1; shift
> > +       fold "$name"
> > +       "$@"
> > +       local ret=$?
> > +       unfold "$name"
> > +       return $ret
> > +}
> 
> We don't have to fiddle with the return value, because we run (almost
> all of) our build scripts with 'set -e', i.e. if the command fails then
> the script will exit immediately.

Yeah, that's probably enough for our simple scripts, though I have been
bit by "set -e" vagaries before (e.g., calling the function inside a
conditional block).

-Peff

Re: [PATCH] travis-ci: build Git during the 'script' phase

[Jeff King]

On Sun, Jan 14, 2018 at 11:43:05AM +0100, SZEDER Gábor wrote:

> On Sat, Jan 13, 2018 at 11:54 AM, Jeff King <peff@peff.net> wrote:
> > I think there's also a similar feature to include timings for each fold,
> > which might be worth pursuing.
> 
> If you look for 'travis_time' in the raw log, you'll find lines like
> these:
> 
>   travis_time:start:01ccbe40
>   $ some-command
>   ... and its output ...
>   travis_time:end:01ccbe40:start=1515840453305552968,finish=1515840471960386859,duration=18654833891
> 
> So it seems doable, but we'll have to do the timekeeping ourselves.
> Running 'time $cmd' is much easier, but that time won't be displayed
> next to the folds, of course.
> Do we really care that much?

I don't care that much (and I wasn't actually planning to push the fold
stuff into a patch, but would instead leave it to you people who were
already working on improving the ci script output ;) ).

Apparently there are exportable bash functions for all of this:

  http://www.garbers.co.za/2017/11/01/code-folding-and-timing-in-travis-ci/

but they're not part of the official API. So relying on them may be even
more questionable than relying on the travis_fold syntax.

-Peff