[PATCH] Fix "spawn id XYZ not open" errors in gdb.mi/mi-exec-run.exp

[PATCH] Fix "spawn id XYZ not open" errors in gdb.mi/mi-exec-run.exp

[Keith Seitz]

Running mi-exec-run.exp on native-extended-gdbserver/-m{32,64}
causes several Tcl errors to appear. For example,

(gdb)
ERROR: : spawn id exp20 not open
    while executing
"expect {
-i exp11 -timeout 10
                -i "$inferior_spawn_id"
                -re ".*Cannot exec.*Permission denied" {
                    set saw_perm_error 1
                    verbose -log "saw..."
    ("uplevel" body line 1)
    invoked from within
"uplevel $body" NONE : spawn id exp20 not open
UNRESOLVED: gdb.mi/mi-exec-run.exp: inferior-tty=separate: mi=separate: force-fail=1: run failure detected (eof)

This is happening because of the way this test is implemented:

        while {1} {
            gdb_expect {
                -i "$inferior_spawn_id"
                -re ".*Cannot exec.*Permission denied" {
                    set saw_perm_error 1
                    verbose -log "saw mi error"
                }
                -i "$gdb_spawn_id"
                -re "\\^error,msg=\"During startup program exited with code 127" {
                    set saw_mi_error 1
                    verbose -log "saw mi error"
                }
               # and so on
            }
        }

The first time this loop is executed, `inferior_spawn_id' is valid. When the
first branch of the expect statement is reached, gdbserver has exited, closing
the spawn_id.  Since we haven't seen the gdb-side error yet, the loop is executed
again.  The first branch now refers to a non-existent spawn_id, leading to the error.

This can be fixed by using exp_continue to loop in expect instead of looping around
expect, which is the approach I have used[1].  Note I've had to update the expected
message for the "During startup..." error message when running with gdbserver.

One other small change I've made is to add a log entry which spills the values of
the two variables, saw_mi_error and saw_perm_error (and updated the log output
for the later).  This should make the log output clearer about why the test failed.

With this patch installed, all the ERRORs disappear, leaving previously masked
FAILs (which I have not attempted to fix).

[1] Anyone know why this test doesn't simply use gdb_test_multiple? I can only
assume that it was intentionally written this way, and I've modified the code with
that assumption. I have tested a version using gdb_test_multiple, and that appears
to work fine, too, if that is preferred. [It still employs exp_continue to fix the
spawn_id errors.]
---
 gdb/testsuite/gdb.mi/mi-exec-run.exp | 53 ++++++++++++++++------------
 1 file changed, 30 insertions(+), 23 deletions(-)

diff --git a/gdb/testsuite/gdb.mi/mi-exec-run.exp b/gdb/testsuite/gdb.mi/mi-exec-run.exp
index eaf7dfa68bf..f397159078f 100644
--- a/gdb/testsuite/gdb.mi/mi-exec-run.exp
+++ b/gdb/testsuite/gdb.mi/mi-exec-run.exp
@@ -89,36 +89,43 @@ proc test {inftty_mode mi_mode force_fail} {
     if {$force_fail} {
 	set saw_perm_error 0
 	set saw_mi_error 0
+	set already_failed 0
 	set test "run failure detected"
 	send_gdb "-exec-run --start\n"
 
-	while {1} {
-	    gdb_expect {
-		-i "$inferior_spawn_id"
-		-re ".*Cannot exec.*Permission denied" {
-		    set saw_perm_error 1
-		    verbose -log "saw mi error"
+	gdb_expect {
+	    -i "$inferior_spawn_id"
+	    -re ".*Cannot exec.*Permission denied" {
+		set saw_perm_error 1
+		verbose -log "saw perm error"
+		if {!$saw_mi_error} {
+		    exp_continue
 		}
-		-i "$gdb_spawn_id"
-		-re "\\^error,msg=\"During startup program exited with code 127" {
-		    set saw_mi_error 1
-		    verbose -log "saw mi error"
-		}
-		timeout {
-		    fail "$test (timeout)"
-		    break
-		}
-		-i "$gdb_main_spawn_id"
-		eof {
-		    fail "$test (eof)"
-		    break
+	    }
+	    -i "$gdb_spawn_id"
+	    -re "\\^error,msg=\"(During startup program exited with code 127|Running .* on the remote target failed)" {
+		set saw_mi_error 1
+		verbose -log "saw mi error"
+		if {!$saw_perm_error} {
+		    exp_continue
 		}
 	    }
-
-	    if {$saw_perm_error && $saw_mi_error} {
-		pass $test
-		break
+	    timeout {
+		set already_failed 1
+		fail "$test (timeout)"
 	    }
+	    -i "$gdb_main_spawn_id"
+	    eof {
+		set already_failed 1
+		fail "$test (eof)"
+	    }
+	}
+
+	if {$saw_perm_error && $saw_mi_error} {
+	    pass $test
+	} elseif {!$already_failed} {
+	    verbose -log "saw_perm_error=$saw_perm_error; saw_mi_error=$saw_mi_error"
+	    fail $test
 	}
     } else {
 	mi_run_cmd "--start"
-- 
2.34.1

Re: [PATCH] Fix "spawn id XYZ not open" errors in gdb.mi/mi-exec-run.exp

[Alexandra Petlanova Hajkova]

On Thu, Feb 24, 2022 at 6:42 PM Keith Seitz via Gdb-patches <
gdb-patches@sourceware.org> wrote:

> Running mi-exec-run.exp on native-extended-gdbserver/-m{32,64}
> causes several Tcl errors to appear. For example,
>
> (gdb)
> ERROR: : spawn id exp20 not open
>     while executing
> "expect {
> -i exp11 -timeout 10
>                 -i "$inferior_spawn_id"
>                 -re ".*Cannot exec.*Permission denied" {
>                     set saw_perm_error 1
>                     verbose -log "saw..."
>     ("uplevel" body line 1)
>     invoked from within
> "uplevel $body" NONE : spawn id exp20 not open
> UNRESOLVED: gdb.mi/mi-exec-run.exp: inferior-tty=separate: mi=separate:
> force-fail=1: run failure detected (eof)
>
> This is happening because of the way this test is implemented:
>
>         while {1} {
>             gdb_expect {
>                 -i "$inferior_spawn_id"
>                 -re ".*Cannot exec.*Permission denied" {
>                     set saw_perm_error 1
>                     verbose -log "saw mi error"
>                 }
>                 -i "$gdb_spawn_id"
>                 -re "\\^error,msg=\"During startup program exited with
> code 127" {
>                     set saw_mi_error 1
>                     verbose -log "saw mi error"
>                 }
>                # and so on
>             }
>         }
> I can see this ERROR on Fedora Rawhide when running:
>

 make check RUNTESTFLAGS="--target_board native-extended-gdbserver"
 TESTS=gdb.mi/mi-exec-run.exp

I'm using glibc-2.35.9000-6.fc37.x86_64 and gcc-12.0.1-0.9.fc37.x86_64.
After applying this patch the TCL errors are gone and I can see one FAIL:

Running
/root/build/gdb/testsuite/../../../binutils-gdb/gdb/testsuite/gdb.mi/mi-exec-run.exp
...
FAIL: gdb.mi/mi-exec-run.exp: inferior-tty=separate: mi=separate:
force-fail=0: breakpoint hit reported on console (timeout)

=== gdb Summary ===

# of expected passes 13
# of unexpected failures 1

Re: [PATCH] Fix "spawn id XYZ not open" errors in gdb.mi/mi-exec-run.exp

[Andrew Burgess]

Keith Seitz via Gdb-patches <gdb-patches@sourceware.org> writes:

> Running mi-exec-run.exp on native-extended-gdbserver/-m{32,64}
> causes several Tcl errors to appear. For example,
>
> (gdb)
> ERROR: : spawn id exp20 not open
>     while executing
> "expect {
> -i exp11 -timeout 10
>                 -i "$inferior_spawn_id"
>                 -re ".*Cannot exec.*Permission denied" {
>                     set saw_perm_error 1
>                     verbose -log "saw..."
>     ("uplevel" body line 1)
>     invoked from within
> "uplevel $body" NONE : spawn id exp20 not open
> UNRESOLVED: gdb.mi/mi-exec-run.exp: inferior-tty=separate: mi=separate: force-fail=1: run failure detected (eof)
>
> This is happening because of the way this test is implemented:
>
>         while {1} {
>             gdb_expect {
>                 -i "$inferior_spawn_id"
>                 -re ".*Cannot exec.*Permission denied" {
>                     set saw_perm_error 1
>                     verbose -log "saw mi error"
>                 }
>                 -i "$gdb_spawn_id"
>                 -re "\\^error,msg=\"During startup program exited with code 127" {
>                     set saw_mi_error 1
>                     verbose -log "saw mi error"
>                 }
>                # and so on
>             }
>         }
>
> The first time this loop is executed, `inferior_spawn_id' is valid. When the
> first branch of the expect statement is reached, gdbserver has exited, closing
> the spawn_id.  Since we haven't seen the gdb-side error yet, the loop is executed
> again.  The first branch now refers to a non-existent spawn_id, leading to the error.
>
> This can be fixed by using exp_continue to loop in expect instead of looping around
> expect, which is the approach I have used[1].  Note I've had to update the expected
> message for the "During startup..." error message when running with gdbserver.
>
> One other small change I've made is to add a log entry which spills the values of
> the two variables, saw_mi_error and saw_perm_error (and updated the log output
> for the later).  This should make the log output clearer about why the test failed.
>
> With this patch installed, all the ERRORs disappear, leaving previously masked
> FAILs (which I have not attempted to fix).
>
> [1] Anyone know why this test doesn't simply use gdb_test_multiple? I can only
> assume that it was intentionally written this way, and I've modified the code with
> that assumption. I have tested a version using gdb_test_multiple, and that appears
> to work fine, too, if that is preferred. [It still employs exp_continue to fix the
> spawn_id errors.]

As the reasoning isn't discussed in the .exp file, the commit message,
or in the original mailing list thread, I'd assume it was just an
oversight.  If you see the same pass/fail using the gdb_test_multiple,
then I think it woud be a nice cleanup to switch over.

But I'm just as happy with what you have below, if you don't want to
make the extra change.

Thanks,
Andrew



> ---
>  gdb/testsuite/gdb.mi/mi-exec-run.exp | 53 ++++++++++++++++------------
>  1 file changed, 30 insertions(+), 23 deletions(-)
>
> diff --git a/gdb/testsuite/gdb.mi/mi-exec-run.exp b/gdb/testsuite/gdb.mi/mi-exec-run.exp
> index eaf7dfa68bf..f397159078f 100644
> --- a/gdb/testsuite/gdb.mi/mi-exec-run.exp
> +++ b/gdb/testsuite/gdb.mi/mi-exec-run.exp
> @@ -89,36 +89,43 @@ proc test {inftty_mode mi_mode force_fail} {
>      if {$force_fail} {
>  	set saw_perm_error 0
>  	set saw_mi_error 0
> +	set already_failed 0
>  	set test "run failure detected"
>  	send_gdb "-exec-run --start\n"
>  
> -	while {1} {
> -	    gdb_expect {
> -		-i "$inferior_spawn_id"
> -		-re ".*Cannot exec.*Permission denied" {
> -		    set saw_perm_error 1
> -		    verbose -log "saw mi error"
> +	gdb_expect {
> +	    -i "$inferior_spawn_id"
> +	    -re ".*Cannot exec.*Permission denied" {
> +		set saw_perm_error 1
> +		verbose -log "saw perm error"
> +		if {!$saw_mi_error} {
> +		    exp_continue
>  		}
> -		-i "$gdb_spawn_id"
> -		-re "\\^error,msg=\"During startup program exited with code 127" {
> -		    set saw_mi_error 1
> -		    verbose -log "saw mi error"
> -		}
> -		timeout {
> -		    fail "$test (timeout)"
> -		    break
> -		}
> -		-i "$gdb_main_spawn_id"
> -		eof {
> -		    fail "$test (eof)"
> -		    break
> +	    }
> +	    -i "$gdb_spawn_id"
> +	    -re "\\^error,msg=\"(During startup program exited with code 127|Running .* on the remote target failed)" {
> +		set saw_mi_error 1
> +		verbose -log "saw mi error"
> +		if {!$saw_perm_error} {
> +		    exp_continue
>  		}
>  	    }
> -
> -	    if {$saw_perm_error && $saw_mi_error} {
> -		pass $test
> -		break
> +	    timeout {
> +		set already_failed 1
> +		fail "$test (timeout)"
>  	    }
> +	    -i "$gdb_main_spawn_id"
> +	    eof {
> +		set already_failed 1
> +		fail "$test (eof)"
> +	    }
> +	}
> +
> +	if {$saw_perm_error && $saw_mi_error} {
> +	    pass $test
> +	} elseif {!$already_failed} {
> +	    verbose -log "saw_perm_error=$saw_perm_error; saw_mi_error=$saw_mi_error"
> +	    fail $test
>  	}
>      } else {
>  	mi_run_cmd "--start"
> -- 
> 2.34.1

Re: [PATCH] Fix "spawn id XYZ not open" errors in gdb.mi/mi-exec-run.exp

[Keith Seitz]

On 2/28/22 09:32, Andrew Burgess wrote:
> Keith Seitz via Gdb-patches <gdb-patches@sourceware.org> writes:
> 
>> [1] Anyone know why this test doesn't simply use gdb_test_multiple? I can only
>> assume that it was intentionally written this way, and I've modified the code with
>> that assumption. I have tested a version using gdb_test_multiple, and that appears
>> to work fine, too, if that is preferred. [It still employs exp_continue to fix the
>> spawn_id errors.]
> 
> As the reasoning isn't discussed in the .exp file, the commit message,
> or in the original mailing list thread, I'd assume it was just an
> oversight.  If you see the same pass/fail using the gdb_test_multiple,
> then I think it woud be a nice cleanup to switch over.

I've tried testing this a bit more, and it looks like gdb_test_multiple
"interferes" with the testing because of all the built-in matches. So we see
"spurious" (as far as this test is concerned) "Process no longer exists" errors,
and these end up racy between runs.

So in that case, I will retract the gdb_test_multiple bit. I wonder if this
was discussed this on IRC in the distant past?

Thanks for the review!

Keith