Re: [PATCH 1/4] travis-ci: use 'set -x' in 'ci/*' scripts for extra tracing output

["SZEDER Gábor" <szeder.dev@gmail.com>]

On Thu, Dec 14, 2017 at 12:10 AM, Lars Schneider
<larsxschneider@gmail.com> wrote:
>
>> On 12 Dec 2017, at 19:43, SZEDER Gábor <szeder.dev@gmail.com> wrote:
>>
>> On Tue, Dec 12, 2017 at 7:00 PM, Lars Schneider
>> <larsxschneider@gmail.com> wrote:
>>>
>>>> On 12 Dec 2017, at 00:34, SZEDER Gábor <szeder.dev@gmail.com> wrote:
>>>>
>>>> While the build logic was embedded in our '.travis.yml', Travis CI
>>>> used to produce a nice trace log including all commands executed in
>>>> those embedded scriptlets.  Since 657343a60 (travis-ci: move Travis CI
>>>> code into dedicated scripts, 2017-09-10), however, we only see the
>>>> name of the dedicated scripts, but not what those scripts are actually
>>>> doing, resulting in a less useful trace log.  A patch later in this
>>>> series will move setting environment variables from '.travis.yml' to
>>>> the 'ci/*' scripts, so not even those will be included in the trace
>>>> log.
>>>>
>>>> Use 'set -x' in 'ci/lib-travisci.sh', which is sourced in most other
>>>> 'ci/*' scripts, so we get trace log about the commands executed in all
>>>> of those scripts.
>>>
>>> I kind of did that intentionally to avoid clutter in the logs.
>>> However, I also agree with your reasoning. Therefore, the change
>>> looks good to me!
>>
>> Great, 'cause I'm starting to have second thoughts about this change :)
>>
>> It sure helped a lot while I worked on this patch series and a couple of
>> other Travis CI related patches (will submit them later)...  OTOH it
>> definitely creates clutter in the trace log.  The worst offender might
>> be 'ci/print-test-failures.sh', which iterates over all
>> 't/test-results/*.exit' files to find which tests failed and to show
>> their output, and 'set -x' makes every iteration visible.  And we have
>> about 800 tests, which means 800 iterations.  Yuck.
>>
>> Perhaps we should use other means to show what's going on instead, e.g.
>> use more 'echo's and '--verbose' options, or just avoid using '--quiet'.
>> And if some brave souls really want to tweak '.travis.yml' or the 'ci/*'
>> scripts, then they can set 'set -x' for themselves during development...
>> as the patch below shows it's easy enough, just a single character :)
>
> Hm... in that case. Would it be an option to "set -x" only in the header
> of "install-dependencies.sh"?
>
> In "lib-travisci.sh" we could keep your "set -x" and execute
> "set +x" at the end of the file. Wouldn't that give us the
> interesting traces without much clutter (e.g. what is $PATH etc)?

Hmm, that's an idea worth considering.

Scripts like 'run-build.sh', 'run-tests.sh' and 'run-static-analysis.sh'
do basically nothing more than run make with different targets, so on
one hand 'set -x' doesn't cause any clutter in the trace log, on the
other hand there is no benefit from it either.
'run-linux32-docker.sh' runs docker (the command) twice, so it's
basically in the same boat.

I think both 'lib-travisci.sh' and 'install-dependencies.sh' benefit
from 'set -x'.
So does 'test-documentation.sh': it executes about 15 commands, among
them a bunch of 'test -s <file>' which fail quietly.  With 'set -x' we
would see the last executed command and know that that's the one that
failed.

As mentioned above, 'print-test-failures.sh' definitely suffers from
'set -x'.

There is a lot going on in 'run-windows-build.sh', so the output of 'set
-x' might be useful or might be considered too much clutter, I don't
know.  I put Dscho on Cc, I think it's mainly his call.

So it seems that there are more scripts that would benefit from tracing
executed command using 'set -x' than scripts that would suffer because
of it, and it doesn't matter for the rest.  This means we could issue a
'set -x' in 'lib-travisci.sh' and disable it only in
'print-test-failures.sh'.

There is one thing that triggers my OCD: whenever we echo something, it
ends up being duplicated in the trace log, e.g.:

  + echo foo bar baz
  foo bar baz

We could workaround it by writing 'echo "<msg>" >/dev/null', but it
feels hackish and I'm not sure it's worth it.


Gábor

>>>> Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
>>>> ---
>>>> ci/lib-travisci.sh | 2 +-
>>>> 1 file changed, 1 insertion(+), 1 deletion(-)
>>>>
>>>> diff --git a/ci/lib-travisci.sh b/ci/lib-travisci.sh
>>>> index ac05f1f46..a0c8ae03f 100755
>>>> --- a/ci/lib-travisci.sh
>>>> +++ b/ci/lib-travisci.sh
>>>> @@ -23,7 +23,7 @@ skip_branch_tip_with_tag () {
>>>>
>>>> # Set 'exit on error' for all CI scripts to let the caller know that
>>>> # something went wrong
>>>> -set -e
>>>> +set -ex
>>>>
>>>> skip_branch_tip_with_tag
>>>>
>>>> --
>>>> 2.15.1.421.gc469ca1de
>>>>
>>>
>