diff mbox series

Handle timeout warnings in dg-extract-results

Message ID CAKdteOajXXOc=c+EvhrT-BFjmEOkT2bPwyxpP2g5ibtben=_cA@mail.gmail.com
State New
Headers show
Series Handle timeout warnings in dg-extract-results | expand

Commit Message

Christophe Lyon Jan. 23, 2019, 1:16 p.m. UTC
Hi,

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 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.

What do people think about this?

Thanks,

Christophe
2019-01-23  Christophe Lyon  <christophe.lyon@linaro.org>

	contrib/
	* dg-extract-results.py: Keep timeout warnings next to their
	matching test.
	* dg-extract-results.sh: Likewise.

Comments

Iain Sandoe Jan. 26, 2019, 4:43 p.m. UTC | #1
Hi Christophe,

> On 23 Jan 2019, at 13:16, Christophe Lyon <christophe.lyon@linaro.org> wrote:


> 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 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.

> 

> What do people think about this?


It seems a good idea (for those of us with targets prone to timeout issues).
I’m going to give it a try on Darwin.

Iain
> 

> Thanks,

> 

> Christophe

> <dg-extract-results.chlog.txt><dg-extract-results.patch.txt>
Christophe Lyon Jan. 29, 2019, 9:58 a.m. UTC | #2
On Sat, 26 Jan 2019 at 17:43, Iain Sandoe <idsandoe@googlemail.com> wrote:
>

> Hi Christophe,

>

> > On 23 Jan 2019, at 13:16, Christophe Lyon <christophe.lyon@linaro.org> wrote:

>

> > 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 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.

> >

> > What do people think about this?

>

> It seems a good idea (for those of us with targets prone to timeout issues).

> I’m going to give it a try on Darwin.

>


Thanks for taking a look and confirming I'm not the only one having to face
random timeouts :-)
Did it work for you?


> Iain

> >

> > Thanks,

> >

> > Christophe

> > <dg-extract-results.chlog.txt><dg-extract-results.patch.txt>

>
Iain Sandoe Jan. 29, 2019, 10:12 a.m. UTC | #3
Hi Christophe,

> On 29 Jan 2019, at 09:58, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> 

> On Sat, 26 Jan 2019 at 17:43, Iain Sandoe <idsandoe@googlemail.com> wrote:

>> 

>> Hi Christophe,

>> 

>>> On 23 Jan 2019, at 13:16, Christophe Lyon <christophe.lyon@linaro.org> wrote:

>> 

>>> 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 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.

>>> 

>>> What do people think about this?

>> 

>> It seems a good idea (for those of us with targets prone to timeout issues).

>> I’m going to give it a try on Darwin.

>> 

> 

> Thanks for taking a look and confirming I'm not the only one having to face

> random timeouts :-)


My worst-cases are a couple of PCH-related that are still unanalysed.. but those are not the only ones.
+ when I use VMs to cover some of the earlier versions of the system, they are much more prone to occasional timeouts.

> Did it work for you?


So far it’s looking nice… (anything that makes the dg output more stable is Good in my book)

… I am not sure (not checked thoroughly) but I think I saw one case in libgomp testing where it didn’t pick up the timeout, will poke some more at that if i see it again.

thanks for the patch!
Iain
Christophe Lyon Jan. 29, 2019, 10:22 a.m. UTC | #4
On Tue, 29 Jan 2019 at 11:12, Iain Sandoe <idsandoe@googlemail.com> wrote:
>

> Hi Christophe,

>

> > On 29 Jan 2019, at 09:58, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> >

> > On Sat, 26 Jan 2019 at 17:43, Iain Sandoe <idsandoe@googlemail.com> wrote:

> >>

> >> Hi Christophe,

> >>

> >>> On 23 Jan 2019, at 13:16, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> >>

> >>> 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 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.

> >>>

> >>> What do people think about this?

> >>

> >> It seems a good idea (for those of us with targets prone to timeout issues).

> >> I’m going to give it a try on Darwin.

> >>

> >

> > Thanks for taking a look and confirming I'm not the only one having to face

> > random timeouts :-)

>

> My worst-cases are a couple of PCH-related that are still unanalysed.. but those are not the only ones.

> + when I use VMs to cover some of the earlier versions of the system, they are much more prone to occasional timeouts.

>

> > Did it work for you?

>

> So far it’s looking nice… (anything that makes the dg output more stable is Good in my book)

>

> … I am not sure (not checked thoroughly) but I think I saw one case in libgomp testing where it didn’t pick up the timeout, will poke some more at that if i see it again.


If you still have the logs, you can run the script manually.

>

> thanks for the patch!

> Iain

>
Iain Sandoe Jan. 31, 2019, 12:30 p.m. UTC | #5
> On 29 Jan 2019, at 10:22, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> 

> On Tue, 29 Jan 2019 at 11:12, Iain Sandoe <idsandoe@googlemail.com> wrote:

>> 

<SNIP>

>>> Did it work for you?

>> 

>> So far it’s looking nice… (anything that makes the dg output more stable is Good in my book)

>> 

>> … I am not sure (not checked thoroughly) but I think I saw one case in libgomp testing where it didn’t pick up the timeout, will poke some more at that if i see it again.

> 

> If you still have the logs, you can run the script manually.


So it seems that the only library testsuite that uses dg-extract-results is libstdc++v3.  This explains why the script wasn’t applied to libgomp.  It DTRT if applied manually.

I guess an edit of the various library testsuite Makefile(s) to generate the original .sum file as a temp followed by dg-extract-results to the final file would work.  Will try it when I have a few moments (unless you get to it first ;) )

Iain
Christophe Lyon Jan. 31, 2019, 1:04 p.m. UTC | #6
On Thu, 31 Jan 2019 at 13:30, Iain Sandoe <idsandoe@googlemail.com> wrote:
>

>

> > On 29 Jan 2019, at 10:22, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> >

> > On Tue, 29 Jan 2019 at 11:12, Iain Sandoe <idsandoe@googlemail.com> wrote:

> >>

> <SNIP>

>

> >>> Did it work for you?

> >>

> >> So far it’s looking nice… (anything that makes the dg output more stable is Good in my book)

> >>

> >> … I am not sure (not checked thoroughly) but I think I saw one case in libgomp testing where it didn’t pick up the timeout, will poke some more at that if i see it again.

> >

> > If you still have the logs, you can run the script manually.

>

> So it seems that the only library testsuite that uses dg-extract-results is libstdc++v3.  This explains why the script wasn’t applied to libgomp.  It DTRT if applied manually.

Good news.
I didn't imagine there were differences in the way results are
extracted between our various tools/libs.

> I guess an edit of the various library testsuite Makefile(s) to generate the original .sum file as a temp followed by dg-extract-results to the final file would work.  Will try it when I have a few moments (unless you get to it first ;) )


Please do, I don't plan to check libgomp.

Thanks
Christophe

>

> Iain

>
Mike Stump Feb. 1, 2019, 11:13 p.m. UTC | #7
On Jan 23, 2019, at 5:16 AM, Christophe Lyon <christophe.lyon@linaro.org> wrote:
> What do people think about this?


Seems reasonable.
Christophe Lyon Feb. 4, 2019, 8:55 a.m. UTC | #8
On Sat, 2 Feb 2019 at 00:13, Mike Stump <mikestump@comcast.net> wrote:
>

> On Jan 23, 2019, at 5:16 AM, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> > What do people think about this?

>

> Seems reasonable.


Thanks, committed as r268511.

Christophe
Iain Sandoe Feb. 4, 2019, 9:04 a.m. UTC | #9
> On 4 Feb 2019, at 08:55, Christophe Lyon <christophe.lyon@linaro.org> wrote:

> 

> On Sat, 2 Feb 2019 at 00:13, Mike Stump <mikestump@comcast.net> wrote:

>> 

>> On Jan 23, 2019, at 5:16 AM, Christophe Lyon <christophe.lyon@linaro.org> wrote:

>>> What do people think about this?

>> 

>> Seems reasonable.

> 

> Thanks, committed as r268511.


There are a few improvements we might want to look at;
 1) application to the libraries (other than libstdc++)
 2) things are inconsistent between -j1 and -jN check runs because the dg-extract doesn’t seem to be run for j1.
  - this means that the timeout warnings are not changed
  - but it also seems to remove the sorting (for some reason I thought that was part of test_summary), which means that one can’t compare a -j1 run with a -jN run easily (or so it seems from some quick tests).

.. won’t have any cycles for looking at this in the next few weeks - but a “heads up” anyway.

Iain
Rainer Orth Feb. 18, 2019, 8:11 p.m. UTC | #10
Hi Christophe,

> 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 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.

>

> What do people think about this?


I just had a case where your patch broke the generation of go.sum.
This is on Solaris 11.5 with python 2.7.15:

ro@colima 68 > /bin/ksh /vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.sh testsuite/go*/*.sum.sep > testsuite/go/go.sum
Traceback (most recent call last):
  File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 605, in <module>
    Prog().main()
  File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 569, in main
    self.parse_file (filename, file)
  File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 427, in parse_file
    num_variations)
  File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 311, in parse_run
    first_key = key
UnboundLocalError: local variable 'key' referenced before assignment

Before your patch, key cannot have been undefined, now it is.  I've
verified this by removing the WARNING: lines from the two affected
go.sum.sep files and now go.sum creation just works fine.

	Rainer

-- 
-----------------------------------------------------------------------------
Rainer Orth, Center for Biotechnology, Bielefeld University
Christophe Lyon Feb. 19, 2019, 9:28 a.m. UTC | #11
On Mon, 18 Feb 2019 at 21:12, Rainer Orth <ro@cebitec.uni-bielefeld.de> wrote:
>

> Hi Christophe,

>

> > 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 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.

> >

> > What do people think about this?

>

> I just had a case where your patch broke the generation of go.sum.

> This is on Solaris 11.5 with python 2.7.15:

>

> ro@colima 68 > /bin/ksh /vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.sh testsuite/go*/*.sum.sep > testsuite/go/go.sum

> Traceback (most recent call last):

>   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 605, in <module>

>     Prog().main()

>   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 569, in main

>     self.parse_file (filename, file)

>   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 427, in parse_file

>     num_variations)

>   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 311, in parse_run

>     first_key = key

> UnboundLocalError: local variable 'key' referenced before assignment

>

> Before your patch, key cannot have been undefined, now it is.  I've

> verified this by removing the WARNING: lines from the two affected

> go.sum.sep files and now go.sum creation just works fine.

>


Sorry for the breakage.

Can you send me the .sum that cause the problem so that I can reproduce it?

Thanks

Christophe

>         Rainer

>

> --

> -----------------------------------------------------------------------------

> Rainer Orth, Center for Biotechnology, Bielefeld University
Christophe Lyon Feb. 19, 2019, 10:29 a.m. UTC | #12
On Tue, 19 Feb 2019 at 10:28, Christophe Lyon
<christophe.lyon@linaro.org> wrote:
>

> On Mon, 18 Feb 2019 at 21:12, Rainer Orth <ro@cebitec.uni-bielefeld.de> wrote:

> >

> > Hi Christophe,

> >

> > > 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 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.

> > >

> > > What do people think about this?

> >

> > I just had a case where your patch broke the generation of go.sum.

> > This is on Solaris 11.5 with python 2.7.15:

> >

> > ro@colima 68 > /bin/ksh /vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.sh testsuite/go*/*.sum.sep > testsuite/go/go.sum

> > Traceback (most recent call last):

> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 605, in <module>

> >     Prog().main()

> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 569, in main

> >     self.parse_file (filename, file)

> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 427, in parse_file

> >     num_variations)

> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 311, in parse_run

> >     first_key = key

> > UnboundLocalError: local variable 'key' referenced before assignment

> >

> > Before your patch, key cannot have been undefined, now it is.  I've

> > verified this by removing the WARNING: lines from the two affected

> > go.sum.sep files and now go.sum creation just works fine.

> >

>

> Sorry for the breakage.

>

> Can you send me the .sum that cause the problem so that I can reproduce it?

>


So the problem happens when a WARNING is the first result of a new harness.
This is fixed by the attached dg-extract-results.patch2.txt.

While looking at it, I noticed that the ordering wasn't right with the
shell version,
though I did test it before sending the previous patch.
The attached dg-extract-results.patch1.txt makes sure the WARNING: line
appears before the following testcase with the shell version too.

Are both OK?

Christophe


> Thanks

>

> Christophe

>

> >         Rainer

> >

> > --

> > -----------------------------------------------------------------------------

> > Rainer Orth, Center for Biotechnology, Bielefeld University
2019-02-19  Christophe Lyon  <christophe.lyon@linaro.org>

	contrib/
	* dg-extract-results.sh: Fix order of WARNING and following test
	result.


diff --git a/contrib/dg-extract-results.sh b/contrib/dg-extract-results.sh
index e9833c1..86c4246 100755
--- a/contrib/dg-extract-results.sh
+++ b/contrib/dg-extract-results.sh
@@ -350,6 +350,7 @@ BEGIN {
         if (timeout_cnt != 0) {
           printf "%s %08d|%s program timed out.\n", testname, timeout_cnt, timeout_msg >> curfile
           timeout_cnt = 0
+          cnt = cnt + 1
         }
         printf "%s %08d|", testname, cnt >> curfile
         cnt = cnt + 1
2019-02-19  Christophe Lyon  <christophe.lyon@linaro.org>

	contrib/
	* dg-extract-results.py: Handle case where a WARNING happens with
	the first test of a harness.

diff --git a/contrib/dg-extract-results.py b/contrib/dg-extract-results.py
index ed62f73..5bf2f87 100644
--- a/contrib/dg-extract-results.py
+++ b/contrib/dg-extract-results.py
@@ -307,8 +307,8 @@ class Prog:
                       has_warning = 0
                   key = (name, len (harness.results))
                   harness.results.append ((key, line))
-                if not first_key and sort_logs:
-                    first_key = key
+                  if not first_key and sort_logs:
+                      first_key = key
                 if line.startswith ('ERROR: (DejaGnu)'):
                     for i in range (len (self.count_names)):
                         if 'DejaGnu errors' in self.count_names[i]:
Christophe Lyon March 4, 2019, 3:35 p.m. UTC | #13
On Tue, 19 Feb 2019 at 11:29, Christophe Lyon
<christophe.lyon@linaro.org> wrote:
>

> On Tue, 19 Feb 2019 at 10:28, Christophe Lyon

> <christophe.lyon@linaro.org> wrote:

> >

> > On Mon, 18 Feb 2019 at 21:12, Rainer Orth <ro@cebitec.uni-bielefeld.de> wrote:

> > >

> > > Hi Christophe,

> > >

> > > > 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 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.

> > > >

> > > > What do people think about this?

> > >

> > > I just had a case where your patch broke the generation of go.sum.

> > > This is on Solaris 11.5 with python 2.7.15:

> > >

> > > ro@colima 68 > /bin/ksh /vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.sh testsuite/go*/*.sum.sep > testsuite/go/go.sum

> > > Traceback (most recent call last):

> > >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 605, in <module>

> > >     Prog().main()

> > >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 569, in main

> > >     self.parse_file (filename, file)

> > >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 427, in parse_file

> > >     num_variations)

> > >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 311, in parse_run

> > >     first_key = key

> > > UnboundLocalError: local variable 'key' referenced before assignment

> > >

> > > Before your patch, key cannot have been undefined, now it is.  I've

> > > verified this by removing the WARNING: lines from the two affected

> > > go.sum.sep files and now go.sum creation just works fine.

> > >

> >

> > Sorry for the breakage.

> >

> > Can you send me the .sum that cause the problem so that I can reproduce it?

> >

>

> So the problem happens when a WARNING is the first result of a new harness.

> This is fixed by the attached dg-extract-results.patch2.txt.

>

> While looking at it, I noticed that the ordering wasn't right with the

> shell version,

> though I did test it before sending the previous patch.

> The attached dg-extract-results.patch1.txt makes sure the WARNING: line

> appears before the following testcase with the shell version too.

>

> Are both OK?

>


Ping?


> Christophe

>

>

> > Thanks

> >

> > Christophe

> >

> > >         Rainer

> > >

> > > --

> > > -----------------------------------------------------------------------------

> > > Rainer Orth, Center for Biotechnology, Bielefeld University
Rainer Orth March 5, 2019, 2:57 p.m. UTC | #14
Hi Christophe,

> On Tue, 19 Feb 2019 at 10:28, Christophe Lyon

> <christophe.lyon@linaro.org> wrote:

>>

>> On Mon, 18 Feb 2019 at 21:12, Rainer Orth <ro@cebitec.uni-bielefeld.de> wrote:

>> >

>> > Hi Christophe,

>> >

>> > > 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 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.

>> > >

>> > > What do people think about this?

>> >

>> > I just had a case where your patch broke the generation of go.sum.

>> > This is on Solaris 11.5 with python 2.7.15:

>> >

>> > ro@colima 68 > /bin/ksh /vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.sh testsuite/go*/*.sum.sep > testsuite/go/go.sum

>> > Traceback (most recent call last):

>> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 605, in <module>

>> >     Prog().main()

>> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 569, in main

>> >     self.parse_file (filename, file)

>> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 427, in parse_file

>> >     num_variations)

>> >   File "/vol/gcc/src/hg/trunk/local/gcc/../contrib/dg-extract-results.py", line 311, in parse_run

>> >     first_key = key

>> > UnboundLocalError: local variable 'key' referenced before assignment

>> >

>> > Before your patch, key cannot have been undefined, now it is.  I've

>> > verified this by removing the WARNING: lines from the two affected

>> > go.sum.sep files and now go.sum creation just works fine.

>> >

>>

>> Sorry for the breakage.

>>

>> Can you send me the .sum that cause the problem so that I can reproduce it?

>>

>

> So the problem happens when a WARNING is the first result of a new harness.

> This is fixed by the attached dg-extract-results.patch2.txt.

>

> While looking at it, I noticed that the ordering wasn't right with the

> shell version,

> though I did test it before sending the previous patch.

> The attached dg-extract-results.patch1.txt makes sure the WARNING: line

> appears before the following testcase with the shell version too.

>

> Are both OK?


ok for now to avoid silently losing considerable parts of the test
results.  However, I've lots of problems with the current approach which
I'll detail in a separate reply to your original test submissions.

	Rainer

-- 
-----------------------------------------------------------------------------
Rainer Orth, Center for Biotechnology, Bielefeld University
Rainer Orth March 5, 2019, 3:16 p.m. UTC | #15
Hi Christophe,

I know I'm coming quite late to this, but I've got quite a number of
problems with your approach.

> 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 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.

> 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.

> 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.

* 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.

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

	Rainer

-- 
-----------------------------------------------------------------------------
Rainer Orth, Center for Biotechnology, Bielefeld University
Christophe Lyon March 5, 2019, 4:10 p.m. UTC | #16
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
diff mbox series

Patch

diff --git a/contrib/dg-extract-results.py b/contrib/dg-extract-results.py
index 4b02a5b..ed62f73 100644
--- a/contrib/dg-extract-results.py
+++ b/contrib/dg-extract-results.py
@@ -239,6 +239,7 @@  class Prog:
         harness = None
         segment = None
         final_using = 0
+        has_warning = 0
 
         # If this is the first run for this variation, add any text before
         # the first harness to the header.
@@ -292,8 +293,20 @@  class Prog:
                 # Ugly hack to get the right order for gfortran.
                 if name.startswith ('gfortran.dg/g77/'):
                     name = 'h' + name
-                key = (name, len (harness.results))
-                harness.results.append ((key, line))
+                # If we have a time out warning, make sure it appears
+                # before the following testcase diagnostic: we insert
+                # the testname before 'program' so that sort faces a
+                # list of testhanes.
+                if line.startswith ('WARNING: program timed out'):
+                  has_warning = 1
+                else:
+                  if has_warning == 1:
+                      key = (name, len (harness.results))
+                      myline = 'WARNING: %s program timed out.\n' % name
+                      harness.results.append ((key, myline))
+                      has_warning = 0
+                  key = (name, len (harness.results))
+                  harness.results.append ((key, line))
                 if not first_key and sort_logs:
                     first_key = key
                 if line.startswith ('ERROR: (DejaGnu)'):
diff --git a/contrib/dg-extract-results.sh b/contrib/dg-extract-results.sh
index 6ee3d26..e9833c1 100755
--- a/contrib/dg-extract-results.sh
+++ b/contrib/dg-extract-results.sh
@@ -298,6 +298,8 @@  BEGIN {
   cnt=0
   print_using=0
   need_close=0
+  has_timeout=0
+  timeout_cnt=0
 }
 /^EXPFILE: / {
   expfiles[expfileno] = \$2
@@ -329,16 +331,36 @@  BEGIN {
   # Ugly hack for gfortran.dg/dg.exp
   if ("$TOOL" == "gfortran" && testname ~ /^gfortran.dg\/g77\//)
     testname="h"testname
+  if (\$1 == "WARNING:" && \$2 == "program" && \$3 == "timed" && (\$4 == "out" || \$4 == "out.")) {
+        has_timeout=1
+        timeout_cnt=cnt
+  } else {
+  # Prepare timeout replacement message in case it's needed
+    timeout_msg=\$0
+    sub(\$1, "WARNING:", timeout_msg)
+  }
 }
 /^$/ { if ("$MODE" == "sum") next }
 { if (variant == curvar && curfile) {
     if ("$MODE" == "sum") {
-      printf "%s %08d|", testname, cnt >> curfile
-      cnt = cnt + 1
+      # Do not print anything if the current line is a timeout
+      if (has_timeout == 0) {
+        # If the previous line was a timeout,
+        # insert the full current message without keyword
+        if (timeout_cnt != 0) {
+          printf "%s %08d|%s program timed out.\n", testname, timeout_cnt, timeout_msg >> curfile
+          timeout_cnt = 0
+        }
+        printf "%s %08d|", testname, cnt >> curfile
+        cnt = cnt + 1
+        filewritten[curfile]=1
+        need_close=1
+        if (timeout_cnt == 0)
+          print >> curfile
+      }
+
+      has_timeout=0
     }
-    filewritten[curfile]=1
-    need_close=1
-    print >> curfile
   } else
     next
 }