Re: [PATCH] Handle timeout warnings in dg-extract-results

[Christophe Lyon <christophe dot lyon at linaro dot org>]

On Tue, 5 Mar 2019 at 16:17, Rainer Orth <ro@cebitec.uni-bielefeld.de> wrote:
>
> Hi Christophe,
>
> I know I'm coming quite late to this, but I've got quite a number of
> problems with your approach.

Thanks for your feedback

> > dg-extract-results currently moves lines like
> > WARNING: program timed out
> > at the end of each .exp section when it generates .sum files.
>
> This is only true when dg-extract-results.py is used.  When it is
> disabled or no python present and thus the shell version is used, this
> issues doesn't exist.  There are other even more severe issues with how

The machines I used all have python, I had to hack the .sh version to avoid
using the python one to make sure I applied the same changes to both.

However, the .sh version does call 'sort' in some cases.
If you feed it with an input like:
Running my.exp ...
PASS: test1
WARNING: program timed out
PASS: test2
Running my.exp ...
PASS: test3
WARNING: program timed out
PASS: test4
(that is, twice the same .exp), the output is:
* before my patch:
Running my.exp ...
WARNING: program timed out
WARNING: program timed out
PASS: test1
PASS: test2
PASS: test3
PASS: test4

* after my patch:
Running my.exp ...
PASS: test1
PASS: test2
WARNING: test2 program timed out.
PASS: test3
PASS: test4
WARNING: test4 program timed out.

> the python version sorts lines, as has been observed in the gdb
> community:
>
>         https://sourceware.org/ml/gdb-patches/2018-10/msg00007.html
>
> Even when passing just a single .sum files to dg-extract-results.py, the
> order changes.
>
I tested only with gcc results, for which there might not be the same problem
(the tests are run in alphabetical order within one .exp file). Do you know
why results are sorted in the first place?

> > This is because it sorts its output based on the 2nd field, which is
> > normally the testname as in:
> > FAIL: gcc.c-torture/execute/20020129-1.c   -O2 -flto
> > -fno-use-linker-plugin -flto-partition=none  execution test
> >
> > As you can notice 'program' comes after
> > gcc.c-torture/execute/20020129-1.c alphabetically, and generally after
> > most (all?) GCC testnames.
> >
> > This is a bit of a pain when trying to handle transient test failures
> > because you can no longer match such a WARNING line to its FAIL
> > counterpart.
> >
> > The attached patch changes this behavior by replacing the line
> > WARNING: program timed out
> > with
> > WARNING: gcc.c-torture/execute/20020129-1.c   -O2 -flto
> > -fno-use-linker-plugin -flto-partition=none  execution test program
> > timed out
> >
> > The effect is that this line will now appear immediately above the
> > FAIL: gcc.c-torture/execute/20020129-1.c   -O2 -flto
> > -fno-use-linker-plugin -flto-partition=none  execution test
> > so that it's easier to match them.
> >
> >
> > I'm not sure how much people depend on the .sum format, I also
> > considered emitting
> > WARNING: program timed out gcc.c-torture/execute/20020129-1.c   -O2
> > -flto -fno-use-linker-plugin -flto-partition=none  execution test
> >
> > I also restricted the patch to handling only 'program timed out'
> > cases, to avoid breaking other things.
> >
> > I considered fixing this in Dejagnu, but it seemed more complicated,
> > and would delay adoption in GCC anyway.
>
> I fear this is the wrong approach: DejaGnu owns the .sum format and they
> need to be involved in extensions.  Besides, it should be possible to
> satisfy the need to have this approved and incorporated upstream and not
> having to wait for a long time until gcc can use it: AFAICS it should be
> possible to wrap DejaGnu's warning proc in a gcc-local version that
> checks for the "program timed out" arg and extracts the test name from
> the caller that has it (dg-test) using uplevel.  I've just not checked
> yet if the call depth from dg-test to warning is constant in the case we
> care about.

I looked at that some time ago, but never managed to find a solution
that I thought would be easily acceptable. I feared that some
people/scripts depend on the actual message format and was
reluctant to do that. But your proposal sounds reasonable.

As you say, changing DejaGnu means it will take time to have the patch
widely used. Changing gcc-local harness can break other scripts,
hence I thought it was safer to change the consumer of .sum files.

> > What do people think about this?
>
> I've more problems with your approach:
>
> * When done in dg-extrace-results.sh/py, it only works for parallel
>   tests.  Both sequential tests (like libgomp and several others) and
>   sequential builds don't get the additional information.  Having to
>   filter every single .sum/.log file through dg-e-r seems totally
>   wasteful to me.
Sorry, in our testing we focus on c/c++/fortran so I missed the
others. However, my understanding of your comments is that
sequential builds do not suffer from this ordering problem?

> * Right now, your patch fabricates misleading timeout information,
>   e.g. I've seen
>
> WARNING: g++.dg/cpp0x/enum32.C  -std=c++14  (test for errors, line 24) program timed out.
>
>   where the original g++.sum file has
>
> WARNING: program timed out
> PASS: g++.dg/cpp0x/enum32.C  -std=c++14  (test for errors, line 24)
> PASS: g++.dg/cpp0x/enum32.C  -std=c++14 (test for excess errors)
>
>   and the original g++.log
>
> /vol/gcc/src/hg/trunk/local/gcc/testsuite/g++.dg/cpp0x/enum32.C: In function 'int main()':
> /vol/gcc/src/hg/trunk/local/gcc/testsuite/g++.dg/cpp0x/enum32.C:24:7: error: 'C::D C::y' is private within this context
> /vol/gcc/src/hg/trunk/local/gcc/testsuite/g++.dg/cpp0x/enum32.C:19:4: note: declared private here
> WARNING: program timed out
> compiler exited with status 1
> PASS: g++.dg/cpp0x/enum32.C  -std=c++14  (test for errors, line 24)
> PASS: g++.dg/cpp0x/enum32.C  -std=c++14 (test for excess errors)
>
>   The only two places where DejaGnu can emit the "program timed out"
>   message is for either the compilation timing out or exection timeouts.
>   So the only messages that make sense would pertain to those, not stuff
>   about other tests.
>
Looks like I didn't anticipate that WARNING could be followed by PASS...
Isn't that test failing??

> I think those issues warrant persueing the alternative approach I've
> lined out above.
Yes.

I'll commit my update (in my previous mail), and I can revert both
when you come up with a fix using your alternative approach.

Thanks

Christophe

>
>         Rainer
>
> --
> -----------------------------------------------------------------------------
> Rainer Orth, Center for Biotechnology, Bielefeld University