travis-ci: build Git during the 'script' phase

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.

---

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

index 4684b3f4f..5f5ee4f3b 100644
@@ -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:

similarity index 80%
rename from ci/run-tests.sh
rename to ci/run-build-and-tests.sh
index 22355f009..d3a094603 100755
@@ -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

deleted file mode 100755
index 4f940d103..000000000
@@ -1,8 +0,0 @@
-#!/bin/sh
-#
-# Build Git
-#
-
-. ${0%/*}/lib-travisci.sh
-
-make --jobs=2

2.16.0.rc1.67.g706959270

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

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

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.

I'm unconvinced :)

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

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:

index 07f27c7270..8c830aa3c0 100755
@@ -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

index d3a094603f..12b2590230 100755
@@ -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

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

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

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

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.

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