[PATCH] gdb/testsuite: better handle failures in simavr board, reap simavr process

[PATCH] gdb/testsuite: better handle failures in simavr board, reap simavr process

[Simon Marchi]

This patch makes a few adjustments to the simavr.exp to handle tests
that error out more gracefully.  I put all the changes in the same patch
because right now it's in a very bad shape, so it's very painful to do
small incremental adjustements.  I found that with these changes, it
becomes reasonably stable.

For example, the gdb.base/step-over-syscall.exp test is a bit buggy
(stuff for another patch...), in that it calls gdb_load (through
clean_restart) with a file that doesn't exist.  The gdb_load
implementation in simavr.exp gets called with a file that doesn't exist,
and simavr (expectedly) fails to start.

When this happens, we currently leave the $simavr_spawn_id variable set.
However, because the simavr process has terminated, its spawn id is
closed.  When the next test tries to close the previous connection to
simavr, it fails to, and this error is thrown:

    ERROR: close: spawn id exp86 not open
        while executing
    "close -i $simavr_spawn_id"
        (procedure "gdb_load" line 18)
        invoked from within

In other words, any test ran after step-over-syscall.exp will have
simavr.exp's gdb_load fail on it.

This patch tries to make sure that simavr.exp's gdb_load only leaves
simavr_spawn_id set if everything went fine.  If we couldn't start
simavr, don't see the expected output, or fail to connect to it, we
close the spawn id (if needed) and unset simavr_spawn_id.

As an additional precaution, I added a catch around the "close the
previous connection" code.  Ideally, this shouldn't be necessary, but I
bet there are other similar scenarios where we might try to close an
already close spawn id.  So I think displaying a warning is better than
messing up all following tests.

Also, the board never wait'ed for the simavr process, resulting in tons
of zombie simavr processes hanging around.  This patch adds some calls
to "wait" whenever we close the connection (or realize it is already
closed), which seems to fix the problem.

Finally I switched a `gdb_expect` to bare `expect`, where we wait for
the "listening" message from simavr.  I found it necessary because
gdb_expect (through remote_expect) adds a `-i <gdb spawn id> -timeout
10`.  So if for some reason the GDB process has crashed in the mean
time, this expect will unexpectedly error out with a `spawn id <gdb
spawn id> not open`.  Therefore, change `gdb_expect` to `expect` so that
we only deal with simavr's spawn id here.

Here are the results on TESTS="gdb.base/*.exp" before:

    # of expected passes		4816
    # of unexpected failures	4433
    # of known failures		2
    # of unresolved testcases	300
    # of untested testcases		143
    # of unsupported tests		7
    # of paths in test names	2
    # of duplicate test names	10

and after:

    # of expected passes		21957
    # of unexpected failures	1564
    # of expected failures		8
    # of unknown successes		1
    # of known failures		31
    # of unresolved testcases	532
    # of untested testcases		153
    # of unsupported tests		28
    # of paths in test names	2
    # of duplicate test names	32

I tested using simavr's current master (7c254e2081b5).

gdb/testsuite/ChangeLog:

	* boards/simavr.exp (gdb_load): Catch errors when closing
	previous connection.  Close connection, wait for process and
	unset simavr_spawn_id on failure.

Change-Id: I695fc765e1c22e1d1dc0b08e0f5141244986b868
---
 gdb/testsuite/boards/simavr.exp | 37 +++++++++++++++++++++++++++++----
 1 file changed, 33 insertions(+), 4 deletions(-)

diff --git a/gdb/testsuite/boards/simavr.exp b/gdb/testsuite/boards/simavr.exp
index 386febfbfd8..1bd02261f50 100644
--- a/gdb/testsuite/boards/simavr.exp
+++ b/gdb/testsuite/boards/simavr.exp
@@ -70,7 +70,12 @@ proc gdb_load { file } {
 
     # Close any previous simavr instance.
     if { $simavr_spawn_id != "" } {
-	close -i $simavr_spawn_id
+	verbose -log "simavr: closing previous spawn id $simavr_spawn_id"
+	if [catch { close -i $simavr_spawn_id } != 0] {
+	    warning "simavr: failed to close connection to previous simavr instance"
+	}
+
+	wait -i $simavr_spawn_id
 	set simavr_spawn_id ""
     }
 
@@ -79,16 +84,40 @@ proc gdb_load { file } {
     verbose -log "Spawning simavr: $cmd"
     eval $cmd
     set simavr_spawn_id $spawn_id
-    gdb_expect {
+
+    verbose -log "simavr: simavr spawned with spawn id $simavr_spawn_id, pid [exp_pid $simavr_spawn_id]"
+
+    # Wait for "listening on port" message of simavr.
+    expect {
 	-i $simavr_spawn_id -re ".*avr_gdb_init listening on port 1234" {}
-	timeout { error "unable to start simavr" }
+	timeout {
+	    verbose -log "simavr: timeout, closing simavr spawn id"
+	    close -i $simavr_spawn_id
+	    verbose -log "simavr: timeout, waiting for simavr process exit"
+	    wait -i $simavr_spawn_id
+	    set simavr_spawn_id ""
+	    error "unable to start simavr: timeout"
+	}
+	eof {
+	    verbose -log "simavr: eof, waiting for simavr process exit"
+	    wait -i $simavr_spawn_id
+	    set simavr_spawn_id ""
+	    error "unable to start simavr: eof"
+	}
     }
 
     # Connect to simavr.
     send_gdb "target remote :1234\n"
     gdb_expect {
 	-re ".*Remote debugging using :1234.*\[\r\n\]+$gdb_prompt $" {}
-	timeout { error "unable to connect to simavr stub" }
+	timeout {
+	    verbose -log "simavr: unable to connect to simavr, closing simavr spawn id"
+	    close -i $simavr_spawn_id
+	    verbose -log "simavr: unable to connect to simavr, waiting for simavr process exit"
+	    wait -i $simavr_spawn_id
+	    set simavr_spawn_id ""
+	    error "unable to connect to simavr stub"
+	}
     }
 
     return 0
-- 
2.27.0

Re: [PATCH] gdb/testsuite: better handle failures in simavr board, reap simavr process

[Simon Marchi]

On 2020-06-22 10:50 a.m., Simon Marchi via Gdb-patches wrote:
> This patch makes a few adjustments to the simavr.exp to handle tests
> that error out more gracefully.  I put all the changes in the same patch
> because right now it's in a very bad shape, so it's very painful to do
> small incremental adjustements.  I found that with these changes, it
> becomes reasonably stable.
> 
> For example, the gdb.base/step-over-syscall.exp test is a bit buggy
> (stuff for another patch...), in that it calls gdb_load (through
> clean_restart) with a file that doesn't exist.  The gdb_load
> implementation in simavr.exp gets called with a file that doesn't exist,
> and simavr (expectedly) fails to start.
> 
> When this happens, we currently leave the $simavr_spawn_id variable set.
> However, because the simavr process has terminated, its spawn id is
> closed.  When the next test tries to close the previous connection to
> simavr, it fails to, and this error is thrown:
> 
>     ERROR: close: spawn id exp86 not open
>         while executing
>     "close -i $simavr_spawn_id"
>         (procedure "gdb_load" line 18)
>         invoked from within
> 
> In other words, any test ran after step-over-syscall.exp will have
> simavr.exp's gdb_load fail on it.
> 
> This patch tries to make sure that simavr.exp's gdb_load only leaves
> simavr_spawn_id set if everything went fine.  If we couldn't start
> simavr, don't see the expected output, or fail to connect to it, we
> close the spawn id (if needed) and unset simavr_spawn_id.
> 
> As an additional precaution, I added a catch around the "close the
> previous connection" code.  Ideally, this shouldn't be necessary, but I
> bet there are other similar scenarios where we might try to close an
> already close spawn id.  So I think displaying a warning is better than
> messing up all following tests.
> 
> Also, the board never wait'ed for the simavr process, resulting in tons
> of zombie simavr processes hanging around.  This patch adds some calls
> to "wait" whenever we close the connection (or realize it is already
> closed), which seems to fix the problem.
> 
> Finally I switched a `gdb_expect` to bare `expect`, where we wait for
> the "listening" message from simavr.  I found it necessary because
> gdb_expect (through remote_expect) adds a `-i <gdb spawn id> -timeout
> 10`.  So if for some reason the GDB process has crashed in the mean
> time, this expect will unexpectedly error out with a `spawn id <gdb
> spawn id> not open`.  Therefore, change `gdb_expect` to `expect` so that
> we only deal with simavr's spawn id here.
> 
> Here are the results on TESTS="gdb.base/*.exp" before:
> 
>     # of expected passes		4816
>     # of unexpected failures	4433
>     # of known failures		2
>     # of unresolved testcases	300
>     # of untested testcases		143
>     # of unsupported tests		7
>     # of paths in test names	2
>     # of duplicate test names	10
> 
> and after:
> 
>     # of expected passes		21957
>     # of unexpected failures	1564
>     # of expected failures		8
>     # of unknown successes		1
>     # of known failures		31
>     # of unresolved testcases	532
>     # of untested testcases		153
>     # of unsupported tests		28
>     # of paths in test names	2
>     # of duplicate test names	32
> 
> I tested using simavr's current master (7c254e2081b5).
> 
> gdb/testsuite/ChangeLog:
> 
> 	* boards/simavr.exp (gdb_load): Catch errors when closing
> 	previous connection.  Close connection, wait for process and
> 	unset simavr_spawn_id on failure.

I pushed this patch.

Simon