[PATCH 1/2] GDB/testsuite: Avoid timeout lowering

[PATCH 1/2] GDB/testsuite: Avoid timeout lowering

[Maciej W. Rozycki]

Hi,

 The recent change to introduce `gdb_reverse_timeout' turned out 
ineffective for board setups that set the `gdb,timeout' target variable.  
A lower `gdb,timeout' setting takes precedence and defeats the effect of 
`gdb_reverse_timeout'.  This is because the global timeout is overridden 
in gdb_test_multiple and then again in gdb_expect.

 Three timeout variables are taken into account in these two places, in 
this precedence:

1. The `gdb,timeout' target variable.

2. The caller's local `timeout' variable (upvar timeout)

3. The global `timeout' variable.

This precedence is obeyed by gdb_test_multiple strictly.  OTOH gdb_expect 
will select the higher of the two formers and will only take the latter 
into account if none of the formers is present.  However the two timeout 
selections are conceptually the same and gdb_test_multiple does its only 
for the purpose of passing it down to gdb_expect.

 Therefore I decided there is no point to keep carrying on this 
duplication and removed the sequence from gdb_test_multiple, however 
retaining the `upvar timeout' variable definition.  This way gdb_expect 
will still access gdb_test_multiple's caller `timeout' variable (if any) 
via its own `upvar timeout' reference.

 Now as to the sequence in gdb_expect.  In addition to the three variables 
described above it also takes a timeout argument into account, as the 
fourth value to choose from.  It is currently used if it is higher than 
the timeout selected from the variables as described above.

 With the timeout selection code from gdb_test_multiple gone, gone is also 
the most prominent use of this timeout argument, it's now used in a couple 
of places only, mostly within this test framework library code itself for 
preparatory commands or suchlike.  With this being the case this timeout 
selection code can be simplified as follows:

1. Among the three timeout variables, the highest is always chosen.  This 
   is so that a test case doesn't inadvertently lower a high value timeout 
   needed by slow target boards.  This is what all test cases use.

2. Any timeout argument takes precedence.  This is for special cases such 
   as within the framework library code, e.g. it doesn't make sense to 
   send `set height 0' with a timeout of 7200 seconds.  This is a local 
   command that does not interact with the target and setting a high 
   timeout here only risks a test suite run taking ages if it goes astray 
   for some reason.

3. The fallback timeout of 60s remains.

I have successfully regression tested this change on arm-linux-gnueabi and 
mips-linux-gnu targets running gdbserver on real hardware and in the 
former case also in QEMU run in the system emulation mode.

 OK to apply?

2014-07-24  Maciej W. Rozycki  <macro@codesourcery.com>

	gdb/testsuite/
	* lib/gdb.exp (gdb_test_multiple): Remove code to select the 
	timeout, don't pass one down to gdb_expect.
	(gdb_expect): Rework timeout selection.

  Maciej

gdb-test-timeout.diff
Index: gdb-fsf-trunk-quilt/gdb/testsuite/lib/gdb.exp
===================================================================
--- gdb-fsf-trunk-quilt.orig/gdb/testsuite/lib/gdb.exp	2014-07-09 22:20:42.528922292 +0100
+++ gdb-fsf-trunk-quilt/gdb/testsuite/lib/gdb.exp	2014-07-12 14:21:16.338935555 +0100
@@ -789,21 +789,6 @@ proc gdb_test_multiple { command message
 	}
     }
 
-    if [target_info exists gdb,timeout] {
-	set tmt [target_info gdb,timeout]
-    } else {
-	if [info exists timeout] {
-	    set tmt $timeout
-	} else {
-	    global timeout
-	    if [info exists timeout] {
-		set tmt $timeout
-	    } else {
-		set tmt 60
-	    }
-	}
-    }
-
     set code {
 	-re ".*A problem internal to GDB has been detected" {
 	    fail "$message (GDB internal error)"
@@ -909,7 +894,7 @@ proc gdb_test_multiple { command message
     }
 
     set result 0
-    set code [catch {gdb_expect $tmt $code} string]
+    set code [catch {gdb_expect $code} string]
     if {$code == 1} {
 	global errorInfo errorCode
 	return -code error -errorinfo $errorInfo -errorcode $errorCode $string
@@ -3070,35 +3055,27 @@ proc gdb_expect { args } {
 	set expcode $args
     }
 
+    # A timeout argument takes precedence, otherwise of all the timeouts
+    # select the largest.
+    upvar #0 timeout gtimeout
     upvar timeout timeout
-
-    if [target_info exists gdb,timeout] {
+    if [info exists atimeout] {
+	set tmt $atimeout
+    } else {
+	set tmt 0
 	if [info exists timeout] {
-	    if { $timeout < [target_info gdb,timeout] } {
-		set gtimeout [target_info gdb,timeout]
-	    } else {
-		set gtimeout $timeout
-	    }
-	} else {
-	    set gtimeout [target_info gdb,timeout]
+	    set tmt $timeout
 	}
-    }
-
-    if ![info exists gtimeout] {
-	global timeout
-	if [info exists timeout] {
-	    set gtimeout $timeout
+	if { [info exists gtimeout] && $gtimeout > $tmt } {
+	    set tmt $gtimeout
 	}
-    }
-
-    if [info exists atimeout] {
-	if { ![info exists gtimeout] || $gtimeout < $atimeout } {
-	    set gtimeout $atimeout
+	if { [target_info exists gdb,timeout]
+	     && [target_info gdb,timeout] > $tmt } {
+	    set tmt [target_info gdb,timeout]
 	}
-    } else {
-	if ![info exists gtimeout] {
+	if { $tmt == 0 } {
 	    # Eeeeew.
-	    set gtimeout 60
+	    set tmt 60
 	}
     }
 
@@ -3113,7 +3090,7 @@ proc gdb_expect { args } {
 	}
     }
     set code [catch \
-	{uplevel remote_expect host $gtimeout $expcode} string]
+	{uplevel remote_expect host $tmt $expcode} string]
     if [info exists old_val] {
 	set remote_suppress_flag $old_val
     } else {

[PATCH 2/2] GDB/testsuite: Add/correct gdb.reverse timeout tweaks

[Maciej W. Rozycki]

Hi,

 There are three cases in two scripts in the gdb.reverse subset that take 
a particularly long time.  Two of them are already attempted to take care 
of by extending the timeout from the default.  The remaining one has no 
precautions taken.  The timeout extension is ineffective though, it is 
done by adding a constant rather than by scaling and as a result while it 
may work for target boards that get satisfied with the detault test 
timeout of 10s, it does not serve its purpose for slower ones.

 Here are indicative samples of execution times (in seconds) observed for 
these cases respectively, for an ARMv7 Panda board running Linux and a 
`-march=armv5te' multilib:

PASS: gdb.reverse/sigall-reverse.exp: continue to signal exit
elapsed: 385
PASS: gdb.reverse/until-precsave.exp: run to end of main
elapsed: 4440
PASS: gdb.reverse/until-precsave.exp: save process recfile
elapsed: 965

for the same board and a `-mthumb -march=armv5te' multilib:

PASS: gdb.reverse/sigall-reverse.exp: continue to signal exit
elapsed: 465
PASS: gdb.reverse/until-precsave.exp: run to end of main
elapsed: 4191
PASS: gdb.reverse/until-precsave.exp: save process recfile
elapsed: 669

and for QEMU in the system emulation mode and a `-march=armv4t' 
multilib:

PASS: gdb.reverse/sigall-reverse.exp: continue to signal exit
elapsed: 45
PASS: gdb.reverse/until-precsave.exp: run to end of main
elapsed: 433
PASS: gdb.reverse/until-precsave.exp: save process recfile
elapsed: 104

Based on the performance of other tests these two test configurations have 
their default timeout set to 450s and 60s respectively.

 The remaining two multilibs (`-mthumb -march=armv4t' and `-mthumb 
-march=armv7-a') do not produce test results usable enough to have data 
available for these cases.

 Based on these results I have tweaked timeouts for these cases as 
follows.  This, together with a suitable board timeout setting, removes 
timeouts for these cases.  Note that for the default timeout of 10s the 
new setting for the first case in gdb.reverse/until-precsave.exp is 
compatible with the old one, just a bit higher to keep the convention of 
longer timeouts to remain multiples of 30s.  The second case there does 
not need such a high setting so I have lowered it a bit to avoid an
unnecessary delay where this test case genuinely times out.

 Tested with arm-linux-gnueabi, as described above.  OK to apply?

2014-07-24  Maciej W. Rozycki  <macro@codesourcery.com>

	gdb/testsuite/
	* gdb.reverse/sigall-reverse.exp: Increase the timeout by a factor 
	of 2 for a slow test case.  Take the `gdb,timeout' target setting
	into account for this calculation.
	* gdb.reverse/until-precsave.exp: Increase the timeout by a factor
	of 15 and 3 respectively rather than adding 120 for a pair of slow 
	test cases.  Take the `gdb,timeout' target setting into account 
	for this calculation.

  Maciej

gdb-test-reverse-timeout.diff
Index: gdb-fsf-trunk-quilt/gdb/testsuite/gdb.reverse/sigall-reverse.exp
===================================================================
--- gdb-fsf-trunk-quilt.orig/gdb/testsuite/gdb.reverse/sigall-reverse.exp	2014-05-30 01:43:19.638974509 +0100
+++ gdb-fsf-trunk-quilt/gdb/testsuite/gdb.reverse/sigall-reverse.exp	2014-05-30 01:45:14.148928207 +0100
@@ -262,9 +262,18 @@ gdb_test "continue" \
     "get signal TERM"
 gdb_test "continue" "Breakpoint.*handle_TERM.*" "send signal TERM"
 
+set savedtimeout $timeout
+if { [target_info exists gdb,timeout]
+     && $timeout < [target_info gdb,timeout] } {
+    set oldtimeout [target_info gdb,timeout]
+} else {
+    set oldtimeout $timeout
+}
+set timeout [expr $oldtimeout * 2]
 gdb_test "continue" "\[process \[0-9\]+ .*" "continue to signal exit" \
     "The next instruction is syscall exit_group.* program...y. or n. " \
     "yes"
+set timeout $savedtimeout
 
 foreach sig [lreverse $signals] {
     test_one_sig_reverse $sig
Index: gdb-fsf-trunk-quilt/gdb/testsuite/gdb.reverse/until-precsave.exp
===================================================================
--- gdb-fsf-trunk-quilt.orig/gdb/testsuite/gdb.reverse/until-precsave.exp	2014-01-03 21:14:07.078675613 +0000
+++ gdb-fsf-trunk-quilt/gdb/testsuite/gdb.reverse/until-precsave.exp	2014-05-30 01:45:14.148928207 +0100
@@ -49,15 +49,22 @@ gdb_test "break $end_of_main" \
     "BP at end of main"
 
 # This can take awhile.
-set oldtimeout $timeout
-set timeout [expr $oldtimeout + 120]
+set savedtimeout $timeout
+if { [target_info exists gdb,timeout]
+     && $timeout < [target_info gdb,timeout] } {
+    set oldtimeout [target_info gdb,timeout]
+} else {
+    set oldtimeout $timeout
+}
+set timeout [expr $oldtimeout * 15]
 gdb_test "continue" "Breakpoint .* set breakpoint 10a here .*" "run to end of main"
 
 # So can this, against gdbserver, for example.
+set timeout [expr $oldtimeout * 3]
 gdb_test "record save $precsave" \
     "Saved core file $precsave with execution log\."  \
     "save process recfile"
-set timeout $oldtimeout
+set timeout $savedtimeout
 
 gdb_test "kill" "" "Kill process, prepare to debug log file" \
     "Kill the program being debugged\\? \\(y or n\\) " "y"

Re: [PATCH 1/2] GDB/testsuite: Avoid timeout lowering

[Yao Qi]

On 07/25/2014 06:38 AM, Maciej W. Rozycki wrote:
>  With the timeout selection code from gdb_test_multiple gone, gone is also 
> the most prominent use of this timeout argument, it's now used in a couple 
> of places only, mostly within this test framework library code itself for 
> preparatory commands or suchlike.  With this being the case this timeout 
> selection code can be simplified as follows:
> 
> 1. Among the three timeout variables, the highest is always chosen.  This 
>    is so that a test case doesn't inadvertently lower a high value timeout 
>    needed by slow target boards.  This is what all test cases use.
> 
> 2. Any timeout argument takes precedence.  This is for special cases such 
>    as within the framework library code, e.g. it doesn't make sense to 
>    send `set height 0' with a timeout of 7200 seconds.  This is a local 
>    command that does not interact with the target and setting a high 
>    timeout here only risks a test suite run taking ages if it goes astray 
>    for some reason.
> 
> 3. The fallback timeout of 60s remains.

Maciej,
IWBN to put the descriptions about timeout selection into the comments
of proc gdb_expect.

I don't see anything wrong in this patch.

-- 
Yao (齐尧)

Re: [PATCH 1/2] GDB/testsuite: Avoid timeout lowering

[Pedro Alves]

On 07/25/2014 02:37 AM, Yao Qi wrote:
> On 07/25/2014 06:38 AM, Maciej W. Rozycki wrote:
>>  With the timeout selection code from gdb_test_multiple gone, gone is also 
>> the most prominent use of this timeout argument, it's now used in a couple 
>> of places only, mostly within this test framework library code itself for 
>> preparatory commands or suchlike.  With this being the case this timeout 
>> selection code can be simplified as follows:
>>
>> 1. Among the three timeout variables, the highest is always chosen.  This 
>>    is so that a test case doesn't inadvertently lower a high value timeout 
>>    needed by slow target boards.  This is what all test cases use.
>>
>> 2. Any timeout argument takes precedence.  This is for special cases such 
>>    as within the framework library code, e.g. it doesn't make sense to 
>>    send `set height 0' with a timeout of 7200 seconds.  This is a local 
>>    command that does not interact with the target and setting a high 
>>    timeout here only risks a test suite run taking ages if it goes astray 
>>    for some reason.

Indeed.  It feels like a host vs target timeout concept.  That is, we
can still have a slow remote host, but that's a different vector of
slow vs a slow target.

>>
>> 3. The fallback timeout of 60s remains.
> 
> Maciej,
> IWBN to put the descriptions about timeout selection into the comments
> of proc gdb_expect.

Agreed.  Or even somewhere more central, and have gdb_expect
gdb_test_multiple, etc. refer to that.

> I don't see anything wrong in this patch.

Me neither.

Thanks,
Pedro Alves

Re: [PATCH 2/2] GDB/testsuite: Add/correct gdb.reverse timeout tweaks

[Pedro Alves]

Looks good to me.

I wonder though, whether:

On 07/24/2014 11:39 PM, Maciej W. Rozycki wrote:
> +set savedtimeout $timeout
> +if { [target_info exists gdb,timeout]
> +     && $timeout < [target_info gdb,timeout] } {
> +    set oldtimeout [target_info gdb,timeout]
> +} else {
> +    set oldtimeout $timeout
> +}
> +set timeout [expr $oldtimeout * 2]

... this pattern can be somewhat factored into a
procedure? That'd also serve the duty of being the
simple place we document it.

>  gdb_test "continue" "\[process \[0-9\]+ .*" "continue to signal exit" \


Thanks,
Pedro Alves

Re: [PATCH 1/2] GDB/testsuite: Avoid timeout lowering

[Maciej W. Rozycki]

On Tue, 29 Jul 2014, Pedro Alves wrote:

> >> 2. Any timeout argument takes precedence.  This is for special cases such 
> >>    as within the framework library code, e.g. it doesn't make sense to 
> >>    send `set height 0' with a timeout of 7200 seconds.  This is a local 
> >>    command that does not interact with the target and setting a high 
> >>    timeout here only risks a test suite run taking ages if it goes astray 
> >>    for some reason.
> 
> Indeed.  It feels like a host vs target timeout concept.  That is, we
> can still have a slow remote host, but that's a different vector of
> slow vs a slow target.

 Hmm, we may consider making the distinction more prominent somehow.  No 
idea outright exactly how, however I'll see if anything smart pops into my 
mind sometime.

> >> 3. The fallback timeout of 60s remains.
> > 
> > Maciej,
> > IWBN to put the descriptions about timeout selection into the comments
> > of proc gdb_expect.
> 
> Agreed.  Or even somewhere more central, and have gdb_expect
> gdb_test_multiple, etc. refer to that.

 I'll think about it, unless any of you beats me to it. ;)

> > I don't see anything wrong in this patch.
> 
> Me neither.

 Applied now, thanks for your review.

  Maciej

Re: [PATCH 2/2] GDB/testsuite: Add/correct gdb.reverse timeout tweaks

[Maciej W. Rozycki]

On Tue, 29 Jul 2014, Pedro Alves wrote:

> Looks good to me.

 Thanks, I have applied this change now.

> I wonder though, whether:
> 
> On 07/24/2014 11:39 PM, Maciej W. Rozycki wrote:
> > +set savedtimeout $timeout
> > +if { [target_info exists gdb,timeout]
> > +     && $timeout < [target_info gdb,timeout] } {
> > +    set oldtimeout [target_info gdb,timeout]
> > +} else {
> > +    set oldtimeout $timeout
> > +}
> > +set timeout [expr $oldtimeout * 2]
> 
> ... this pattern can be somewhat factored into a
> procedure? That'd also serve the duty of being the
> simple place we document it.

 Good point, that would be a nice improvement indeed.

 I have been continuously being dragged off to various other stuff 
recently though so if I were to consider this improvement a prerequisite 
to pushing the timeout tweaks I have made here, they may well have not 
ended up integrated within a reasonable time frame.  I have therefore 
committed them as they are, as noted above, so as not to let perfect be 
the enemy of good.  I'll keep in mind that our timeouts would benefit from 
some polishing yet and hopefully get back to it sometime sooner rather 
than later.  Unless someone beats me to it, that is -- I won't mind that, 
not a little bit.

 The stuff is easy to grep for, so the pieces to improve should be easy to 
identify.

  Maciej