[v2] gdb/testsuite: Avoid infinite loop in gdb.reverse/step-reverse.exp

Message ID 20230601214239.209822-1-thiago.bauermann@linaro.org
State New
Headers
Series [v2] gdb/testsuite: Avoid infinite loop in gdb.reverse/step-reverse.exp |

Commit Message

Thiago Jung Bauermann June 1, 2023, 9:42 p.m. UTC
  This testcase sometimes gets stuck in a loop for hours when running in our
CI.  The problem is that due to an issue unrelated to reverse debugging the
inferior exits early, and because of the overly generic ".*" pattern the
testcase keeps sending the "next" command without noticing that the
inferior is gone.

gdb_test_multiple has a pattern to detect that "The program is not being
run.", but since it is placed after the patterns from the caller it won't
be triggered.  It also has a timeout pattern but because it is triggered
between successful matches, each time the test matches the '-re -wrap ".*"'
this counts as a successful match and the timeout is reset.

Since the test binary is compiled with debug information, fix by changing
one of the generic patterns to match entering the main function and the
other one to match the source code line number that is shown by GDB right
after the "step" command.

Also, as a precaution add a maximum number of times the "next" command will
be sent.

Co-Authored-By: Tom de Vries <tdevries@suse.de>
---

Changes since v1:
- Added maximum number of iterations (code provided by Tom).
- Changed one of the patterns to match the main function (suggested by Bruno).
- Clarified why the timeout pattern isn't effective (explanation from Andrew).

Tom,

Most of the patch now is the iteration-counting code. Since I copied it
from your email, I thought it made sense to record you as co-author.
I hope it's ok.

 gdb/testsuite/gdb.reverse/step-reverse.exp | 25 ++++++++++++++++++++--
 1 file changed, 23 insertions(+), 2 deletions(-)


base-commit: d987df5c95340a8b41b23d68ad6a8f9f33485835
  

Comments

Guinevere Larsen June 5, 2023, 8 a.m. UTC | #1
On 01/06/2023 23:42, Thiago Jung Bauermann wrote:
> This testcase sometimes gets stuck in a loop for hours when running in our
> CI.  The problem is that due to an issue unrelated to reverse debugging the
> inferior exits early, and because of the overly generic ".*" pattern the
> testcase keeps sending the "next" command without noticing that the
> inferior is gone.
>
> gdb_test_multiple has a pattern to detect that "The program is not being
> run.", but since it is placed after the patterns from the caller it won't
> be triggered.  It also has a timeout pattern but because it is triggered
> between successful matches, each time the test matches the '-re -wrap ".*"'
> this counts as a successful match and the timeout is reset.
>
> Since the test binary is compiled with debug information, fix by changing
> one of the generic patterns to match entering the main function and the
> other one to match the source code line number that is shown by GDB right
> after the "step" command.
>
> Also, as a precaution add a maximum number of times the "next" command will
> be sent.
>
> Co-Authored-By: Tom de Vries <tdevries@suse.de>
> ---
>
> Changes since v1:
> - Added maximum number of iterations (code provided by Tom).
> - Changed one of the patterns to match the main function (suggested by Bruno).
> - Clarified why the timeout pattern isn't effective (explanation from Andrew).
>
> Tom,
>
> Most of the patch now is the iteration-counting code. Since I copied it
> from your email, I thought it made sense to record you as co-author.
> I hope it's ok.
>
>   gdb/testsuite/gdb.reverse/step-reverse.exp | 25 ++++++++++++++++++++--
>   1 file changed, 23 insertions(+), 2 deletions(-)
>
> diff --git a/gdb/testsuite/gdb.reverse/step-reverse.exp b/gdb/testsuite/gdb.reverse/step-reverse.exp
> index 729218d4cb8c..c70d2fcb5166 100644
> --- a/gdb/testsuite/gdb.reverse/step-reverse.exp
> +++ b/gdb/testsuite/gdb.reverse/step-reverse.exp
> @@ -247,6 +247,7 @@ gdb_test_multiple "step" "$test_message" {
>   gdb_test "next" ".*NEXT OVER THIS CALL.*" "reverse next over call"
>   
>   set step_out 0
> +set max_iterations 1000
>   gdb_test_multiple "next" "reverse next over recursion" {
>       -re -wrap ".*NEXT OVER THIS RECURSION.*" {
>   	pass "$gdb_test_name"
> @@ -257,11 +258,18 @@ gdb_test_multiple "next" "reverse next over recursion" {
>       }
>   }
>   if { "$step_out" == 1 } {
> +    set iterations 0
>       gdb_test_multiple "next" "stepping out of recursion" {
>   	-re -wrap "NEXT OVER THIS RECURSION.*" {
>   	    set step_out 0
>   	}
> -	-re -wrap ".*" {
> +	-re -wrap "^main .*"  {
> +	    incr iterations
> +	    if { $iterations == $max_iterations } {
> +		fail "$gdb_test_name (reached $max_iterations iterations)"
> +		return
> +	    }
> +

I'm fine with the idea of a maximum iteration count (even if I find it 
unnecessary), but your use of it here is incorrect. What your code is 
doing is doing is _only_ exiting once you see GDB returning to the main 
function $max_iterations times.

  if { "$step_out" == 1 } {
      gdb_test_multiple "next" "stepping out of recursion" {
         -re -wrap "NEXT OVER THIS RECURSION.*" {
             set step_out 0
+           pass "$gdb_test_name"
         }
-       -re -wrap ".*" {
+       -re -wrap "^main.*" {
+           pass "$gdb_test_name"
+       }
+       -re -wrap "^\[0-9\].*" {
+           incr iterations
+           if { $iterations == $max_iterations } {
+               fail "$gdb_test_name (reached $max_iterations iterations)"
+               return
+           }
             send_gdb "next\n"
             exp_continue
         }
      }
  }

And I wonder if we'd like to add a pass if step_out was never set to 1, 
so we don't get fewer passes when everything works? Not sure, I'd defer 
to Andrew or Tom on this one.
  
Thiago Jung Bauermann June 5, 2023, 11:35 p.m. UTC | #2
Bruno Larsen <blarsen@redhat.com> writes:

> On 01/06/2023 23:42, Thiago Jung Bauermann wrote:
>> @@ -257,11 +258,18 @@ gdb_test_multiple "next" "reverse next over recursion" {
>>       }
>>   }
>>   if { "$step_out" == 1 } {
>> +    set iterations 0
>>       gdb_test_multiple "next" "stepping out of recursion" {
>>   	-re -wrap "NEXT OVER THIS RECURSION.*" {
>>   	    set step_out 0
>>   	}
>> -	-re -wrap ".*" {
>> +	-re -wrap "^main .*"  {
>> +	    incr iterations
>> +	    if { $iterations == $max_iterations } {
>> +		fail "$gdb_test_name (reached $max_iterations iterations)"
>> +		return
>> +	    }
>> +
>
> I'm fine with the idea of a maximum iteration count (even if I find it unnecessary), but
> your use of it here is incorrect. What your code is doing is doing is _only_ exiting once
> you see GDB returning to the main function $max_iterations times.
>
>  if { "$step_out" == 1 } {
>      gdb_test_multiple "next" "stepping out of recursion" {
>         -re -wrap "NEXT OVER THIS RECURSION.*" {
>             set step_out 0
> +           pass "$gdb_test_name"
>         }
> -       -re -wrap ".*" {
> +       -re -wrap "^main.*" {
> +           pass "$gdb_test_name"
> +       }
> +       -re -wrap "^\[0-9\].*" {
> +           incr iterations
> +           if { $iterations == $max_iterations } {
> +               fail "$gdb_test_name (reached $max_iterations iterations)"
> +               return
> +           }
>             send_gdb "next\n"
>             exp_continue
>         }
>      }
>  }

Ouch, sorry about that. The "$step_out == 1" case doesn't trigger for
me, so I'm not testing that part of the patch and I didn't notice the
problem.

I sent a v3 with a slightly different change from what you posted above.
I put the "^main.*" part in the beginning of the "NEXT OVER THIS
RECURSION.*" regex. I thought that it makes sense because both strings
should appear in the same command output according to the excerpt you
pasted in the thread discussing v1 of this patch. Please let me know if
you would prefer me to use the alternative above.

> And I wonder if we'd like to add a pass if step_out was never set to 1, so we don't get
> fewer passes when everything works? Not sure, I'd defer to Andrew or Tom on this one.

IMHO it's not necessary for the number of PASS to be the same if the
testcase passes or fails, but I'll wait for their input.
  
Guinevere Larsen June 6, 2023, 7:18 a.m. UTC | #3
On 06/06/2023 01:35, Thiago Jung Bauermann wrote:
> Bruno Larsen <blarsen@redhat.com> writes:
>
>> On 01/06/2023 23:42, Thiago Jung Bauermann wrote:
>>> @@ -257,11 +258,18 @@ gdb_test_multiple "next" "reverse next over recursion" {
>>>        }
>>>    }
>>>    if { "$step_out" == 1 } {
>>> +    set iterations 0
>>>        gdb_test_multiple "next" "stepping out of recursion" {
>>>    	-re -wrap "NEXT OVER THIS RECURSION.*" {
>>>    	    set step_out 0
>>>    	}
>>> -	-re -wrap ".*" {
>>> +	-re -wrap "^main .*"  {
>>> +	    incr iterations
>>> +	    if { $iterations == $max_iterations } {
>>> +		fail "$gdb_test_name (reached $max_iterations iterations)"
>>> +		return
>>> +	    }
>>> +
>> I'm fine with the idea of a maximum iteration count (even if I find it unnecessary), but
>> your use of it here is incorrect. What your code is doing is doing is _only_ exiting once
>> you see GDB returning to the main function $max_iterations times.
>>
>>   if { "$step_out" == 1 } {
>>       gdb_test_multiple "next" "stepping out of recursion" {
>>          -re -wrap "NEXT OVER THIS RECURSION.*" {
>>              set step_out 0
>> +           pass "$gdb_test_name"
>>          }
>> -       -re -wrap ".*" {
>> +       -re -wrap "^main.*" {
>> +           pass "$gdb_test_name"
>> +       }
>> +       -re -wrap "^\[0-9\].*" {
>> +           incr iterations
>> +           if { $iterations == $max_iterations } {
>> +               fail "$gdb_test_name (reached $max_iterations iterations)"
>> +               return
>> +           }
>>              send_gdb "next\n"
>>              exp_continue
>>          }
>>       }
>>   }
> Ouch, sorry about that. The "$step_out == 1" case doesn't trigger for
> me, so I'm not testing that part of the patch and I didn't notice the
> problem.
>
> I sent a v3 with a slightly different change from what you posted above.
> I put the "^main.*" part in the beginning of the "NEXT OVER THIS
> RECURSION.*" regex. I thought that it makes sense because both strings
> should appear in the same command output according to the excerpt you
> pasted in the thread discussing v1 of this patch. Please let me know if
> you would prefer me to use the alternative above.

oops, my bad! I forgot the fact that "NEXT OVER THIS RECURSION" comes at 
the same time, and didn't think to check that. Since both of those 
outputs are together, there is no point in having 2 cases. You can 
choose to keep either one, and given my blunder here I would suggest 
keeping the "^main.*" regexp, but that is up to you.

Sorry for the run-around with this one.
  
Thiago Jung Bauermann June 6, 2023, 1 p.m. UTC | #4
Bruno Larsen <blarsen@redhat.com> writes:

> On 06/06/2023 01:35, Thiago Jung Bauermann wrote:
>> Bruno Larsen <blarsen@redhat.com> writes:
>>
>>> On 01/06/2023 23:42, Thiago Jung Bauermann wrote:
>>>> @@ -257,11 +258,18 @@ gdb_test_multiple "next" "reverse next over recursion" {
>>>>        }
>>>>    }
>>>>    if { "$step_out" == 1 } {
>>>> +    set iterations 0
>>>>        gdb_test_multiple "next" "stepping out of recursion" {
>>>>    	-re -wrap "NEXT OVER THIS RECURSION.*" {
>>>>    	    set step_out 0
>>>>    	}
>>>> -	-re -wrap ".*" {
>>>> +	-re -wrap "^main .*"  {
>>>> +	    incr iterations
>>>> +	    if { $iterations == $max_iterations } {
>>>> +		fail "$gdb_test_name (reached $max_iterations iterations)"
>>>> +		return
>>>> +	    }
>>>> +
>>> I'm fine with the idea of a maximum iteration count (even if I find it unnecessary),
>>> but
>>> your use of it here is incorrect. What your code is doing is doing is _only_ exiting
>>> once
>>> you see GDB returning to the main function $max_iterations times.
>>>
>>>   if { "$step_out" == 1 } {
>>>       gdb_test_multiple "next" "stepping out of recursion" {
>>>          -re -wrap "NEXT OVER THIS RECURSION.*" {
>>>              set step_out 0
>>> +           pass "$gdb_test_name"
>>>          }
>>> -       -re -wrap ".*" {
>>> +       -re -wrap "^main.*" {
>>> +           pass "$gdb_test_name"
>>> +       }
>>> +       -re -wrap "^\[0-9\].*" {
>>> +           incr iterations
>>> +           if { $iterations == $max_iterations } {
>>> +               fail "$gdb_test_name (reached $max_iterations iterations)"
>>> +               return
>>> +           }
>>>              send_gdb "next\n"
>>>              exp_continue
>>>          }
>>>       }
>>>   }
>> Ouch, sorry about that. The "$step_out == 1" case doesn't trigger for
>> me, so I'm not testing that part of the patch and I didn't notice the
>> problem.
>>
>> I sent a v3 with a slightly different change from what you posted above.
>> I put the "^main.*" part in the beginning of the "NEXT OVER THIS
>> RECURSION.*" regex. I thought that it makes sense because both strings
>> should appear in the same command output according to the excerpt you
>> pasted in the thread discussing v1 of this patch. Please let me know if
>> you would prefer me to use the alternative above.
>
> oops, my bad! I forgot the fact that "NEXT OVER THIS RECURSION" comes at the same time,
> and didn't think to check that. Since both of those outputs are together, there is no
> point in having 2 cases. You can choose to keep either one, and given my blunder here I
> would suggest keeping the "^main.*" regexp, but that is up to you.

To be honest I like the way it is in v3:

	-re -wrap "^main.*NEXT OVER THIS RECURSION.*" {
	    set step_out 0
	    pass "$gdb_test_name"
	}

with the "^main" part anchoring the RE and the "NEXT OVER THIS
RECURSION" part making it clear in which source code line the inferior
is supposed to be. Do you prefer keeping only the "^main.*" part?

> Sorry for the run-around with this one.

No problem at all. Thank you for your reviews and suggestions.
  

Patch

diff --git a/gdb/testsuite/gdb.reverse/step-reverse.exp b/gdb/testsuite/gdb.reverse/step-reverse.exp
index 729218d4cb8c..c70d2fcb5166 100644
--- a/gdb/testsuite/gdb.reverse/step-reverse.exp
+++ b/gdb/testsuite/gdb.reverse/step-reverse.exp
@@ -247,6 +247,7 @@  gdb_test_multiple "step" "$test_message" {
 gdb_test "next" ".*NEXT OVER THIS CALL.*" "reverse next over call"
 
 set step_out 0
+set max_iterations 1000
 gdb_test_multiple "next" "reverse next over recursion" {
     -re -wrap ".*NEXT OVER THIS RECURSION.*" {
 	pass "$gdb_test_name"
@@ -257,11 +258,18 @@  gdb_test_multiple "next" "reverse next over recursion" {
     }
 }
 if { "$step_out" == 1 } {
+    set iterations 0
     gdb_test_multiple "next" "stepping out of recursion" {
 	-re -wrap "NEXT OVER THIS RECURSION.*" {
 	    set step_out 0
 	}
-	-re -wrap ".*" {
+	-re -wrap "^main .*"  {
+	    incr iterations
+	    if { $iterations == $max_iterations } {
+		fail "$gdb_test_name (reached $max_iterations iterations)"
+		return
+	    }
+
 	    send_gdb "next\n"
 	    exp_continue
 	}
@@ -276,9 +284,16 @@  gdb_test_no_output "set exec-dir reverse" "reverse again to test recursion"
 
 gdb_test "step" ".*EXIT RECURSIVE FUNCTION.*" "enter recursive function"
 set seen_recursive_call 0
+set iterations 0
 gdb_test_multiple "next" "step over recursion inside the recursion" {
     -re -wrap ".*RECURSIVE CALL.*" {
 	incr seen_recursive_call
+	incr iterations
+	if { $iterations == $max_iterations } {
+	    fail "$gdb_test_name (reached $max_iterations iterations)"
+	    return
+	}
+
 	send_gdb "next\n"
 	exp_continue
     }
@@ -286,7 +301,13 @@  gdb_test_multiple "next" "step over recursion inside the recursion" {
 	gdb_assert {"$seen_recursive_call" == 1} \
 	    "step over recursion inside the recursion"
     }
-    -re -wrap ".*" {
+    -re -wrap "^\[0-9\].*" {
+	incr iterations
+	if { $iterations == $max_iterations } {
+	    fail "$gdb_test_name (reached $max_iterations iterations)"
+	    return
+	}
+
 	send_gdb "next\n"
 	exp_continue
     }