Re: Regression tester confusion

Re: Regression tester confusion

[Geoff Keating]

> Date: Tue, 07 May 2002 11:27:02 -0700
> From: Mark Mitchell <mark@codesourcery.com>
> Content-Disposition: inline
> 
> I'm confused.  The regression tester seems to be saying that I broke
> mips-elf with my recent checkin to rs6000/sysv4.h, which seems odd.
> 
> Am I going crazy?

There's something odd going on with mips-elf gdb.base/interrupt.exp.
It seems to be failing at random---this is the third time it's
mysteriously appeared.  The symptoms have been that the .log file
contains:

(gdb) PASS: gdb.base/interrupt.exp: call function a second time
continue
Continuing.
PASS: gdb.base/interrupt.exp: continue
data

data
FAIL: gdb.base/interrupt.exp: echo data (timeout)
end of file

The gdb testsuite is looking for the 'data' output, which as you can
see is there, and so the testcase should pass.

The problem seems to happen only when the machine is under other
load---specifically, when the machine is trying to update its binutils
& gdb.  I suspect that dejagnu is not properly matching the regexp
because the extra activity on the machine is causing it to be given
the output in two or more pieces.  The kernel and dejagnu versions on
the two machines (mips-elf is on anubis with a 2.4 kernel, native &
powerpc are on maat with 2.2) are different; hopefully, soon the
dejagnu versions will be synchronized, which should help to narrow
down the problem.

If anyone's seen this before (especially if you fixed it!),
I'd be interested to hear about it.

-- 
- Geoffrey Keating <geoffk@geoffk.org> <geoffk@redhat.com>

Re: Regression tester confusion

[Daniel Jacobowitz]

On Tue, May 07, 2002 at 12:44:05PM -0700, Geoff Keating wrote:
> > Date: Tue, 07 May 2002 11:27:02 -0700
> > From: Mark Mitchell <mark@codesourcery.com>
> > Content-Disposition: inline
> > 
> > I'm confused.  The regression tester seems to be saying that I broke
> > mips-elf with my recent checkin to rs6000/sysv4.h, which seems odd.
> > 
> > Am I going crazy?
> 
> There's something odd going on with mips-elf gdb.base/interrupt.exp.
> It seems to be failing at random---this is the third time it's
> mysteriously appeared.  The symptoms have been that the .log file
> contains:
> 
> (gdb) PASS: gdb.base/interrupt.exp: call function a second time
> continue
> Continuing.
> PASS: gdb.base/interrupt.exp: continue
> data
> 
> data
> FAIL: gdb.base/interrupt.exp: echo data (timeout)
> end of file
> 
> The gdb testsuite is looking for the 'data' output, which as you can
> see is there, and so the testcase should pass.
> 
> The problem seems to happen only when the machine is under other
> load---specifically, when the machine is trying to update its binutils
> & gdb.  I suspect that dejagnu is not properly matching the regexp
> because the extra activity on the machine is causing it to be given
> the output in two or more pieces.  The kernel and dejagnu versions on
> the two machines (mips-elf is on anubis with a 2.4 kernel, native &
> powerpc are on maat with 2.2) are different; hopefully, soon the
> dejagnu versions will be synchronized, which should help to narrow
> down the problem.
> 
> If anyone's seen this before (especially if you fixed it!),
> I'd be interested to hear about it.

This usually means that the previous DejaGNU command did not explicitly
consume enough input... Although in this case, it looks as if there are
an invalid extra \r\n between the 'data's.

The comment two tests up in interrupt.exp sounds as if there's a known
timing problem here.  Did "call function when asleep" fail, causing the
extra newline to get sent?


-- 
Daniel Jacobowitz                           Carnegie Mellon University
MontaVista Software                         Debian GNU/Linux Developer

Re: Regression tester confusion

[Geoff Keating]

> Date: Tue, 7 May 2002 16:13:08 -0400
> From: Daniel Jacobowitz <drow@mvista.com>
...
> This usually means that the previous DejaGNU command did not explicitly
> consume enough input... Although in this case, it looks as if there are
> an invalid extra \r\n between the 'data's.
> 
> The comment two tests up in interrupt.exp sounds as if there's a known
> timing problem here.  Did "call function when asleep" fail, causing the
> extra newline to get sent?

No---this was the first and only failure for interrupt.exp.  This is a
cross to mips-elf, running on the sim, so I think the comment doesn't apply.

The log looks like (through 'cat -A', but may be word-wrapped, sorry):

a^M$
PASS: gdb.base/interrupt.exp: child process ate our char$
^M$
Program received signal SIGINT, Interrupt.^M$
0xa0020298 in main () at
/anubis/mummy/tbox/objs/share/gdb-testsuite/gdb.base/interrupt.c:17^M$
17^I      nbytes = read (0, &x, 1);^M$
(gdb) PASS: gdb.base/interrupt.exp: send_gdb control C$
p func1 ()^M$
$1 = 4^M$
(gdb) PASS: gdb.base/interrupt.exp: call function when asleep$
p func1 ()^M$
$2 = 4^M$
(gdb) PASS: gdb.base/interrupt.exp: call function a second time$
continue^M$
Continuing.^M$
PASS: gdb.base/interrupt.exp: continue$
data^M$
^M$
data^M$
FAIL: gdb.base/interrupt.exp: echo data (timeout)$
end of file^M$
^M$
Program exited normally.^M$
[Switching to process 0]^M$
Current language:  auto; currently asm^M$
(gdb) PASS: gdb.base/interrupt.exp: send end of file$

When the test passes (as it did on the very next run), the output
looks like:

PASS: gdb.base/interrupt.exp: child process ate our char$
^M$
Program received signal SIGINT, Interrupt.^M$
0xa0020298 in main () at
/anubis/mummy/tbox/objs/share/gdb-testsuite/gdb.base/in
terrupt.c:17^M$
17^I      nbytes = read (0, &x, 1);^M$
(gdb) PASS: gdb.base/interrupt.exp: send_gdb control C$
p func1 ()^M$
$1 = 4^M$
(gdb) PASS: gdb.base/interrupt.exp: call function when asleep$
p func1 ()^M$
$2 = 4^M$
(gdb) PASS: gdb.base/interrupt.exp: call function a second time$
continue^M$
Continuing.^M$
^M$
PASS: gdb.base/interrupt.exp: continue$
data^M$
PASS: gdb.base/interrupt.exp: echo data$
data^M$
end of file^M$

... and now I see.  The regexp is:

            -re "^(\r\n|)data\r\n(|data\r\n)$" { pass "echo data" }

But in the failing case, we are getting

data\r\n\r\ndata\r\n

which doesn't match for some reason.  

I think the variation is because one 'data\r\n' is the tty driver
echoing the test harness's input, and the program's output is
'\r\ndata\r\n' (the first \r\n is from earlier).  They are getting
interleaved depending on system load.

-- 
- Geoffrey Keating <geoffk@geoffk.org> <geoffk@redhat.com>

Re: Regression tester confusion

[Michael Elizabeth Chastain]

> There's something odd going on with mips-elf gdb.base/interrupt.exp.
> It seems to be failing at random---this is the third time it's
> mysteriously appeared.  The symptoms have been that the .log file
> contains:

I've seen this before in gdb.base/interrupt.exp and gdb.c++/annota2.exp.
It happens more frequently in gdb.c++/annota2.exp.  I've even seen it
happen on unloaded machines.  It happens to me on native i686-pc-linux-gnu
using tcl 8.3.4, expect 5.33.0, and dejagnu 1.42, both plain and with
FernandoN's kfail patch (which does not touch the core machinery).

I've seen this with identical software on back-to-back runs on an
unloaded machine.  This is definitely an issue with the test harness,
not with the software under test.

I will look into this tomorrow night (I've already got a task for
tonight).

Michael C