Re: [PATCH 1/4] travis-ci: use 'set -x' in 'ci/*' scripts for extra tracing output
- From
SZEDER Gábor <szeder.dev@gmail.com>
- Date
- Dec 14, 2017, 23:51 UTC
- Message-ID
- <CAM0VKjkv0XqHf8s94Wj2DHsD49gTP0M6HU2AY=36Jj-5SYhS9A@mail.gmail.com>
- In-Reply-To
- <77E6AE23-44FF-42E0-94FF-C4B35D913D5B@gmail.com>
On Thu, Dec 14, 2017 at 12:10 AM, Lars Schneider <larsxschneider@gmail.com> wrote:
Show 48 quoted lines
> >> 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
Show 23 quoted lines
>>>> 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
>>>>
>>>
>