[PATCH] gdb/testsuite: address test failures in gdb.mi/mi-multi-commands.exp

[PATCH] gdb/testsuite: address test failures in gdb.mi/mi-multi-commands.exp

[Andrew Burgess]

The gdb.mi/mi-multi-commands.exp test was added in commit:

  commit d08cbc5d3203118da5583296e49273cf82378042
  Date:   Wed Dec 22 12:57:44 2021 +0000

      gdb: unbuffer all input streams when not using readline

And then tweaked in commit:

  commit 144459531dd68a1287905079aaa131b777a8cc82
  Date:   Mon Feb 7 20:35:58 2022 +0000

      gdb/testsuite: relax pattern in new gdb.mi/mi-multi-commands.exp test

The second of these commits was intended to address periodic test
failures that I was seeing, and this change did fix some problems,
but, unfortunately, introduced other issues.

The problem is that the test relies on sending two commands to GDB in
a single write.  As the characters that make these two commands arrive
they are echoed to GDB's console.  However, there is a race between
how quickly the characters are echoed and how quickly GDB decides to
act on the incoming commands.

Usually, both commands are echoed in full before GDB acts on the first
command, but sometimes this is not the case, and GDB can execute the
first command before both commands are fully echoed to the console.
In this case, the output of the first command will be mixed in with
the echoing of the second command.

This mixing of the command echoing and the first command output is
what was causing failures in the original version of the test.

The second commit relaxed the expected output pattern a little, but
was still susceptible to failures, so this commit further relaxes the
pattern.

Now, we look for the first command output with no regard to what is
before, or after the command.  Then we look for the fist mi prompt to
indicate that the first command has completed.

I believe that this change should make the test more stable than it
was before.
---
 gdb/testsuite/gdb.mi/mi-multi-commands.exp | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/gdb/testsuite/gdb.mi/mi-multi-commands.exp b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
index 12b1b482f9a..22b0ccf9aaa 100644
--- a/gdb/testsuite/gdb.mi/mi-multi-commands.exp
+++ b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
@@ -100,9 +100,12 @@ proc run_test { args } {
 	set seen_second_message false
 
 	gdb_test_multiple "" "look for first command output, command length $i" -prompt "$mi_gdb_prompt" {
-	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"\r\n" {
+	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"" {
 		pass $gdb_test_name
 		set seen_first_message true
+		exp_continue
+	    }
+	    -re "\r\n$mi_gdb_prompt" {
 	    }
 	}
 
-- 
2.25.4

Re: [PATCH] gdb/testsuite: address test failures in gdb.mi/mi-multi-commands.exp

[Pedro Alves]

On 2022-03-22 11:03, Andrew Burgess via Gdb-patches wrote:
> The gdb.mi/mi-multi-commands.exp test was added in commit:
> 
>   commit d08cbc5d3203118da5583296e49273cf82378042
>   Date:   Wed Dec 22 12:57:44 2021 +0000
> 
>       gdb: unbuffer all input streams when not using readline
> 
> And then tweaked in commit:
> 
>   commit 144459531dd68a1287905079aaa131b777a8cc82
>   Date:   Mon Feb 7 20:35:58 2022 +0000
> 
>       gdb/testsuite: relax pattern in new gdb.mi/mi-multi-commands.exp test
> 
> The second of these commits was intended to address periodic test
> failures that I was seeing, and this change did fix some problems,
> but, unfortunately, introduced other issues.
> 
> The problem is that the test relies on sending two commands to GDB in
> a single write.  As the characters that make these two commands arrive
> they are echoed to GDB's console.  However, there is a race between
> how quickly the characters are echoed and how quickly GDB decides to
> act on the incoming commands.
> 
> Usually, both commands are echoed in full before GDB acts on the first
> command, but sometimes this is not the case, and GDB can execute the
> first command before both commands are fully echoed to the console.
> In this case, the output of the first command will be mixed in with
> the echoing of the second command.
> 
> This mixing of the command echoing and the first command output is
> what was causing failures in the original version of the test.
> 
> The second commit relaxed the expected output pattern a little, but
> was still susceptible to failures, so this commit further relaxes the
> pattern.
> 
> Now, we look for the first command output with no regard to what is
> before, or after the command.  Then we look for the fist mi prompt to

fist -> first

> indicate that the first command has completed.
> 
> I believe that this change should make the test more stable than it
> was before.
> ---
>  gdb/testsuite/gdb.mi/mi-multi-commands.exp | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/gdb/testsuite/gdb.mi/mi-multi-commands.exp b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
> index 12b1b482f9a..22b0ccf9aaa 100644
> --- a/gdb/testsuite/gdb.mi/mi-multi-commands.exp
> +++ b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
> @@ -100,9 +100,12 @@ proc run_test { args } {
>  	set seen_second_message false
>  
>  	gdb_test_multiple "" "look for first command output, command length $i" -prompt "$mi_gdb_prompt" {
> -	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"\r\n" {
> +	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"" {
>  		pass $gdb_test_name
>  		set seen_first_message true
> +		exp_continue
> +	    }
> +	    -re "\r\n$mi_gdb_prompt" {
>  	    }

Should move the "pass" to the mi_gdb_prompt match too, otherwise if the prompt match ever fails,
then as is this results in a PASS and then, say, a "FAIL ... (timeout)" for the same test.

IIUC, should make the pass conditional on seen_first_message too:

	    -re "\r\n$mi_gdb_prompt" {
                 gdb_assert $seen_first_message $gdb_test_message
  	    }

Re: [PATCH] gdb/testsuite: address test failures in gdb.mi/mi-multi-commands.exp

[Andrew Burgess]

Pedro Alves <pedro@palves.net> writes:

> On 2022-03-22 11:03, Andrew Burgess via Gdb-patches wrote:
>> The gdb.mi/mi-multi-commands.exp test was added in commit:
>> 
>>   commit d08cbc5d3203118da5583296e49273cf82378042
>>   Date:   Wed Dec 22 12:57:44 2021 +0000
>> 
>>       gdb: unbuffer all input streams when not using readline
>> 
>> And then tweaked in commit:
>> 
>>   commit 144459531dd68a1287905079aaa131b777a8cc82
>>   Date:   Mon Feb 7 20:35:58 2022 +0000
>> 
>>       gdb/testsuite: relax pattern in new gdb.mi/mi-multi-commands.exp test
>> 
>> The second of these commits was intended to address periodic test
>> failures that I was seeing, and this change did fix some problems,
>> but, unfortunately, introduced other issues.
>> 
>> The problem is that the test relies on sending two commands to GDB in
>> a single write.  As the characters that make these two commands arrive
>> they are echoed to GDB's console.  However, there is a race between
>> how quickly the characters are echoed and how quickly GDB decides to
>> act on the incoming commands.
>> 
>> Usually, both commands are echoed in full before GDB acts on the first
>> command, but sometimes this is not the case, and GDB can execute the
>> first command before both commands are fully echoed to the console.
>> In this case, the output of the first command will be mixed in with
>> the echoing of the second command.
>> 
>> This mixing of the command echoing and the first command output is
>> what was causing failures in the original version of the test.
>> 
>> The second commit relaxed the expected output pattern a little, but
>> was still susceptible to failures, so this commit further relaxes the
>> pattern.
>> 
>> Now, we look for the first command output with no regard to what is
>> before, or after the command.  Then we look for the fist mi prompt to
>
> fist -> first
>
>> indicate that the first command has completed.
>> 
>> I believe that this change should make the test more stable than it
>> was before.
>> ---
>>  gdb/testsuite/gdb.mi/mi-multi-commands.exp | 5 ++++-
>>  1 file changed, 4 insertions(+), 1 deletion(-)
>> 
>> diff --git a/gdb/testsuite/gdb.mi/mi-multi-commands.exp b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
>> index 12b1b482f9a..22b0ccf9aaa 100644
>> --- a/gdb/testsuite/gdb.mi/mi-multi-commands.exp
>> +++ b/gdb/testsuite/gdb.mi/mi-multi-commands.exp
>> @@ -100,9 +100,12 @@ proc run_test { args } {
>>  	set seen_second_message false
>>  
>>  	gdb_test_multiple "" "look for first command output, command length $i" -prompt "$mi_gdb_prompt" {
>> -	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"\r\n" {
>> +	    -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"" {
>>  		pass $gdb_test_name
>>  		set seen_first_message true
>> +		exp_continue
>> +	    }
>> +	    -re "\r\n$mi_gdb_prompt" {
>>  	    }
>
> Should move the "pass" to the mi_gdb_prompt match too, otherwise if the prompt match ever fails,
> then as is this results in a PASS and then, say, a "FAIL ... (timeout)" for the same test.
>
> IIUC, should make the pass conditional on seen_first_message too:
>
> 	    -re "\r\n$mi_gdb_prompt" {
>                  gdb_assert $seen_first_message $gdb_test_message
>   	    }

Thanks, I made these changes, and pushed this patch.

Andrew