Re: [PATCH 4/4] gdb/testsuite: track if a caching proc calls gdb_exit or not

[Luis Machado <luis.machado@arm.com>]

On 8/7/24 11:08, Luis Machado wrote:
> On 8/7/24 11:00, Andrew Burgess wrote:
>> Andrew Burgess <aburgess@redhat.com> writes:
>>
>>> Luis Machado <luis.machado@arm.com> writes:
>>>
>>>> Hi Andrew,
>>>>
>>>> On 6/3/24 19:16, Andrew Burgess wrote:
>>>>> After a recent patch review I asked myself why can_spawn_for_attach
>>>>> exists.  This proc currently does some checks, and then calls
>>>>> can_spawn_for_attach_1 which is an actual caching proc.
>>>>>
>>>>> The answer is that can_spawn_for_attach exists in order to call
>>>>> gdb_exit the first time can_spawn_for_attach is called within any test
>>>>> script.
>>>>>
>>>>> The reason this is useful is that can_spawn_for_attach_1 calls
>>>>> gdb_exit.  If imagine the user calling can_spawn_for_attach_1 directly
>>>>> then a problem might exist.  Imagine a test written like this:
>>>>>
>>>>>   gdb_start
>>>>>
>>>>>   if { [can_spawn_for_attach_1] } {
>>>>>     ... do stuff that assumes GDB is running ...
>>>>>   }
>>>>>
>>>>> If this test is NOT the first test run, and if an earlier test calls
>>>>> can_spawn_for_attach_1, then when the above test is run the
>>>>> can_spawn_for_attach_1 call will return the cached value and gdb_exit
>>>>> will not be called.
>>>>>
>>>>> But, if the above test IS the first test run then
>>>>> can_spawn_for_attach_1 will not returned the cached value, but will
>>>>> instead compute the cached value, a process that ends up calling
>>>>> gdb_exit.  When the body of the if is executed GDB would no longer be
>>>>> running and the test would fail!
>>>>>
>>>>> So can_spawn_for_attach was added which ensures that we _always_ call
>>>>> gdb_exit the first time can_spawn_for_attach is called within a single
>>>>> test script, this ensures that in the above case, even if the above is
>>>>> not the first test run, gdb_exit will still be called.  This avoids
>>>>> some hidden bugs in the testsuite.
>>>>>
>>>>> However, what I observe is that can_spawn_for_attach is not the only
>>>>> caching proc that calls gdb_exit.  Why does can_spawn_for_attach get
>>>>> special treatment when surely the same issue exists for any other
>>>>> caching proc that calls gdb_exit?
>>>>>
>>>>> I think a better solution is to move the logic from
>>>>> can_spawn_for_attach into cache.exp and generalise it so that it
>>>>> applies to all caching procs.
>>>>>
>>>>> This commit does this by:
>>>>>
>>>>>  1. When the underlying caching proc is executed we wrap gdb_exit.
>>>>>     This wrapper sets a global to true if gdb_exit is called.  The
>>>>>     value of this global is stored in gdb_data_cache (using a ',exit'
>>>>>     suffix), and also written to the cache file if appropriate.
>>>>>
>>>>>  2. When a cached value is returned from gdb_do_cache, if the
>>>>>     underlying proc would have called gdb_exit, and if this is the
>>>>>     first use of the caching proc in this test script, then we call
>>>>>     gdb_exit.
>>>>>
>>>>> When storing the ',exit' value into the on-disk cache file, the flag
>>>>> value is stored on a second line.  Currently every cached value only
>>>>> occupies a single line, and a check is added to ensure this remains
>>>>> true in the future.
>>>>>
>>>>> One issue did come up in testing, a FAIL in gdb.base/break-interp.exp,
>>>>> this was caused by can_spawn_for_attach_1 calling gdb_start without
>>>>> first calling gdb_exit.  Under the old way of doing things
>>>>> can_spawn_for_attach would call gdb_exit _before_ possibly calling the
>>>>> actual caching proc.  Under the new scheme gdb_exit is called _after_
>>>>> calling the actual caching proc.  What was happening was that
>>>>> break-interp.exp would leave GDB running then call
>>>>> can_spawn_for_attach, when the test in can_spawn_for_attach_1 tried to
>>>>> attach to the inferior, state left in the running GDB would cause some
>>>>> unexpected behaviour.  Fixed by having can_spawn_for_attach_1 call
>>>>> gdb_exit before calling gdb_start, this ensures we have a fresh GDB.
>>>>>
>>>>> With this done can_spawn_for_attach_1 can be renamed to
>>>>> can_spawn_for_attach, and the existing can_spawn_for_attach can be
>>>>> deleted.
>>>>> ---
>>>>>  gdb/testsuite/lib/cache.exp | 86 +++++++++++++++++++++++++++++++------
>>>>>  gdb/testsuite/lib/gdb.exp   | 83 +++++++++--------------------------
>>>>>  2 files changed, 93 insertions(+), 76 deletions(-)
>>>>>
>>>>> diff --git a/gdb/testsuite/lib/cache.exp b/gdb/testsuite/lib/cache.exp
>>>>> index e7b9114058b..fef065ec8b0 100644
>>>>> --- a/gdb/testsuite/lib/cache.exp
>>>>> +++ b/gdb/testsuite/lib/cache.exp
>>>>> @@ -46,6 +46,40 @@ proc gdb_do_cache_wrap {real_name args} {
>>>>>      return $result
>>>>>  }
>>>>>  
>>>>> +# Global written to by wrap_gdb_exit.  Set to true if wrap_gdb_exit is
>>>>> +# called.
>>>>> +
>>>>> +set gdb_exit_called false
>>>>> +
>>>>> +# Wrapper around gdb_exit.  Use with_override to replace gdb_exit with
>>>>> +# wrap_gdb_exit, the original gdb_exit is renamed to orig_gdb_exit.
>>>>> +
>>>>> +proc wrap_gdb_exit {} {
>>>>> +    set ::gdb_exit_called true
>>>>> +    orig_gdb_exit
>>>>> +}
>>>>> +
>>>>> +# If DO_EXIT is false then this proc does nothing.  If DO_EXIT is true
>>>>> +# then call gdb_exit the first time this proc is called for each
>>>>> +# unique value of NAME within a single test.  Every subsequent time
>>>>> +# this proc is called within a single test (for a given value of
>>>>> +# NAME), don't call gdb_exit.
>>>>> +
>>>>> +proc gdb_cache_maybe_gdb_exit { name do_exit } {
>>>>> +    if { !$do_exit } {
>>>>> +	return
>>>>> +    }
>>>>> +
>>>>> +    # To track if this proc has been called for NAME we create a
>>>>> +    # global variable.  In gdb_cleanup_globals (see gdb.exp) this
>>>>> +    # global will be deleted when the test has finished.
>>>>> +    set global_name __${name}__cached_gdb_exit_called
>>>>> +    if { ![info exists ::${global_name}] } {
>>>>> +	gdb_exit
>>>>> +	set ::${global_name} true
>>>>> +    }
>>>>> +}
>>>>> +
>>>>>  # A helper for gdb_caching_proc that handles the caching.
>>>>>  
>>>>>  proc gdb_do_cache {name args} {
>>>>> @@ -71,10 +105,12 @@ proc gdb_do_cache {name args} {
>>>>>  
>>>>>      set is_cached 0
>>>>>      if {[info exists gdb_data_cache(${cache_name},value)]} {
>>>>> -	set cached $gdb_data_cache(${cache_name},value)
>>>>> -	verbose "$name: returning '$cached' from cache" 2
>>>>> +	set cached_value $gdb_data_cache(${cache_name},value)
>>>>> +	set cached_exit $gdb_data_cache(${cache_name},exit)
>>>>> +	verbose "$name: returning '$cached_value' from cache" 2
>>>>>  	if { $cache_verify == 0 } {
>>>>> -	    return $cached
>>>>> +	    gdb_cache_maybe_gdb_exit $name $cached_exit
>>>>> +	    return $cached_value
>>>>>  	}
>>>>>  	set is_cached 1
>>>>>      }
>>>>> @@ -83,24 +119,46 @@ proc gdb_do_cache {name args} {
>>>>>  	set cache_filename [make_gdb_parallel_path cache $cache_name]
>>>>>  	if {[file exists $cache_filename]} {
>>>>>  	    set fd [open $cache_filename]
>>>>> -	    set gdb_data_cache(${cache_name},value) [read -nonewline $fd]
>>>>> +	    set content [split [read -nonewline $fd] \n]
>>>>>  	    close $fd
>>>>> -	    set cached $gdb_data_cache(${cache_name},value)
>>>>> -	    verbose "$name: returning '$cached' from file cache" 2
>>>>> +	    set gdb_data_cache(${cache_name},value) [lindex $content 0]
>>>>> +	    set gdb_data_cache(${cache_name},exit) [lindex $content 1]
>>>>> +	    set cached_value $gdb_data_cache(${cache_name},value)
>>>>> +	    set cached_exit $gdb_data_cache(${cache_name},exit)
>>>>> +	    verbose "$name: returning '$cached_value' from file cache" 2
>>>>>  	    if { $cache_verify == 0 } {
>>>>> -		return $cached
>>>>> +		gdb_cache_maybe_gdb_exit $name $cached_exit
>>>>> +		return $cached_value
>>>>>  	    }
>>>>>  	    set is_cached 1
>>>>>  	}
>>>>>      }
>>>>>  
>>>>> -    set real_name gdb_real__$name
>>>>> -    set gdb_data_cache(${cache_name},value) [gdb_do_cache_wrap $real_name {*}$args]
>>>>> +    set ::gdb_exit_called false
>>>>> +    with_override gdb_exit wrap_gdb_exit orig_gdb_exit {
>>>>> +	set real_name gdb_real__$name
>>>>> +	set gdb_data_cache(${cache_name},value) [gdb_do_cache_wrap $real_name {*}$args]
>>>>> +    }
>>>>> +    set gdb_data_cache(${cache_name},exit) $::gdb_exit_called
>>>>> +
>>>>> +    # If a value being stored in the cache contains a newline then
>>>>> +    # when we try to read the value back from an on-disk cache file
>>>>> +    # we'll interpret the second line of the value as the ',exit' value.
>>>>> +    if { [regexp "\[\r\n\]" $gdb_data_cache(${cache_name},value)] } {
>>>>> +	set computed_value $gdb_data_cache(${cache_name},value)
>>>>> +	error "Newline found in value for $cache_name: $computed_value"
>>>>> +    }
>>>>> +
>>>>>      if { $cache_verify == 1 && $is_cached == 1 } {
>>>>> -	set computed $gdb_data_cache(${cache_name},value)
>>>>> -	if { $cached != $computed } {
>>>>> -	    error [join [list "Inconsistent results for $cache_name:"
>>>>> -			 "cached: $cached vs. computed: $computed"]]
>>>>> +	set computed_value $gdb_data_cache(${cache_name},value)
>>>>> +	set computed_exit $gdb_data_cache(${cache_name},exit)
>>>>> +	if { $cached_value != $computed_value } {
>>>>> +	    error [join [list "Inconsistent value results for $cache_name:"
>>>>> +			 "cached: $cached_value vs. computed: $computed_value"]]
>>>>> +	}
>>>>> +	if { $cached_exit != $computed_exit } {
>>>>> +	    error [join [list "Inconsistent exit results for $cache_name:"
>>>>> +			 "cached: $cached_exit vs. computed: $computed_exit"]]
>>>>>  	}
>>>>>      }
>>>>>  
>>>>> @@ -110,9 +168,11 @@ proc gdb_do_cache {name args} {
>>>>>  	# Make sure to write the results file atomically.
>>>>>  	set fd [open $cache_filename.[pid] w]
>>>>>  	puts $fd $gdb_data_cache(${cache_name},value)
>>>>> +	puts $fd $gdb_data_cache(${cache_name},exit)
>>>>>  	close $fd
>>>>>  	file rename -force -- $cache_filename.[pid] $cache_filename
>>>>>      }
>>>>> +    gdb_cache_maybe_gdb_exit $name $gdb_data_cache(${cache_name},exit)
>>>>>      return $gdb_data_cache(${cache_name},value)
>>>>>  }
>>>>>  
>>>>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
>>>>> index 8235d4f28eb..d29fd740f91 100644
>>>>> --- a/gdb/testsuite/lib/gdb.exp
>>>>> +++ b/gdb/testsuite/lib/gdb.exp
>>>>> @@ -6186,14 +6186,23 @@ proc gdb_exit { } {
>>>>>      catch default_gdb_exit
>>>>>  }
>>>>>  
>>>>> -# Helper function for can_spawn_for_attach.  Try to spawn and attach, and
>>>>> -# return 0 only if we cannot attach because it's unsupported.
>>>>> -
>>>>> -gdb_caching_proc can_spawn_for_attach_1 {} {
>>>>> -    # For the benefit of gdb-caching-proc-consistency.exp, which
>>>>> -    # calls can_spawn_for_attach_1 directly.  Keep in sync with
>>>>> -    # can_spawn_for_attach.
>>>>> -    if { [is_remote target] || [target_info exists use_gdb_stub] } {
>>>>> +# Return true if we can spawn a program on the target and attach to
>>>>> +# it.
>>>>> +
>>>>> +gdb_caching_proc can_spawn_for_attach {} {
>>>>> +    # We use exp_pid to get the inferior's pid, assuming that gives
>>>>> +    # back the pid of the program.  On remote boards, that would give
>>>>> +    # us instead the PID of e.g., the ssh client, etc.
>>>>> +    if {[is_remote target]} {
>>>>> +	verbose -log "can't spawn for attach (target is remote)"
>>>>> +	return 0
>>>>> +    }
>>>>> +
>>>>> +    # The "attach" command doesn't make sense when the target is
>>>>> +    # stub-like, where GDB finds the program already started on
>>>>> +    # initial connection.
>>>>> +    if {[target_info exists use_gdb_stub]} {
>>>>> +	verbose -log "can't spawn for attach (target is stub)"
>>>>>  	return 0
>>>>>      }
>>>>>  
>>>>> @@ -6218,6 +6227,9 @@ gdb_caching_proc can_spawn_for_attach_1 {} {
>>>>>      set test_spawn_id [spawn_wait_for_attach_1 $obj]
>>>>>      remote_file build delete $obj
>>>>>  
>>>>> +    # In case GDB is already running.
>>>>> +    gdb_exit
>>>>> +    
>>>>>      gdb_start
>>>>>  
>>>>>      set test_pid [spawn_id_get_pid $test_spawn_id]
>>>>> @@ -6239,61 +6251,6 @@ gdb_caching_proc can_spawn_for_attach_1 {} {
>>>>>      return $res
>>>>>  }
>>>>>  
>>>>> -# Return true if we can spawn a program on the target and attach to
>>>>> -# it.  Calls gdb_exit for the first call in a test-case.
>>>>> -
>>>>> -proc can_spawn_for_attach { } {
>>>>> -    # We use exp_pid to get the inferior's pid, assuming that gives
>>>>> -    # back the pid of the program.  On remote boards, that would give
>>>>> -    # us instead the PID of e.g., the ssh client, etc.
>>>>> -    if {[is_remote target]} {
>>>>> -	verbose -log "can't spawn for attach (target is remote)"
>>>>> -	return 0
>>>>> -    }
>>>>> -
>>>>> -    # The "attach" command doesn't make sense when the target is
>>>>> -    # stub-like, where GDB finds the program already started on
>>>>> -    # initial connection.
>>>>> -    if {[target_info exists use_gdb_stub]} {
>>>>> -	verbose -log "can't spawn for attach (target is stub)"
>>>>> -	return 0
>>>>> -    }
>>>>> -
>>>>> -    # The normal sequence to use for a runtime test like
>>>>> -    # can_spawn_for_attach_1 is:
>>>>> -    # - gdb_exit (don't use a running gdb, we don't know what state it is in),
>>>>> -    # - gdb_start (start a new gdb), and
>>>>> -    # - gdb_exit (cleanup).
>>>>> -    #
>>>>> -    # By making can_spawn_for_attach_1 a gdb_caching_proc, we make it
>>>>> -    # unpredictable which test-case will call it first, and consequently a
>>>>> -    # test-case may pass in say a full test run, but fail when run
>>>>> -    # individually, due to a can_spawn_for_attach call in a location where a
>>>>> -    # gdb_exit (as can_spawn_for_attach_1 does) breaks things.
>>>>> -    # To avoid this, we move the initial gdb_exit out of
>>>>> -    # can_spawn_for_attach_1, guaranteeing that we end up in the same state
>>>>> -    # regardless of whether can_spawn_for_attach_1 is called.  However, that
>>>>> -    # is only necessary for the first call in a test-case, so cache the result
>>>>> -    # in a global (which should be reset after each test-case) to keep track
>>>>> -    # of that.
>>>>> -    #
>>>>> -    # In summary, we distinguish between three cases:
>>>>> -    # - first call in first test-case.  Executes can_spawn_for_attach_1.
>>>>> -    #   Calls gdb_exit, gdb_start, gdb_exit.
>>>>> -    # - first call in following test-cases.  Uses cached result of
>>>>> -    #   can_spawn_for_attach_1.  Calls gdb_exit.
>>>>> -    # - rest.  Use cached result in cache_can_spawn_for_attach_1. Calls no
>>>>> -    #   gdb_start or gdb_exit.
>>>>> -    global cache_can_spawn_for_attach_1
>>>>> -    if { [info exists cache_can_spawn_for_attach_1] } {
>>>>> -	return $cache_can_spawn_for_attach_1
>>>>> -    }
>>>>> -    gdb_exit
>>>>> -
>>>>> -    set cache_can_spawn_for_attach_1 [can_spawn_for_attach_1]
>>>>> -    return $cache_can_spawn_for_attach_1
>>>>> -}
>>>>> -
>>>>>  # Centralize the failure checking of "attach" command.
>>>>>  # Return 0 if attach failed, otherwise return 1.
>>>>>  
>>>>
>>>> This is a bit after the fact, but I tracked down some aarch64 sme test regressions
>>>> to this particular patch. I'm still investigating exactly why it stopped working, but I
>>>> can tell it only happens if we run 2 or more tests in the same run. It is not
>>>> clear if making things parallel has an impact, or if it is just the fact we
>>>> run 2+ tests in the same run.
>>>>
>>>> I suspect we may be calling gdb_exit when we shouldn't, and then things just
>>>> stop working.
>>>>
>>>> ---
>>>>
>>>> Running target unix
>>>> Using /usr/share/dejagnu/baseboards/unix.exp as board description file for target.
>>>> Using /usr/share/dejagnu/config/unix.exp as generic interface file for target.
>>>> Using repos/binutils-gdb/gdb/testsuite/config/unix.exp as tool-and-target-specific interface file.
>>>> Running repos/binutils-gdb/gdb/testsuite/gdb.arch/aarch64-sme-core-0.exp ...
>>>> Running repos/binutils-gdb/gdb/testsuite/gdb.arch/aarch64-sme-regs-unavailable-3.exp ...
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> FAIL: gdb.arch/aarch64-sme-regs-unavailable-3.exp: prctl, vl=32 svl=256: check_regs: incorrect ZA state
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> ERROR: no fileid for ubuntu
>>>> FAIL: gdb.arch/aarch64-sme-regs-unavailable-3.exp: gdb, vl=32 svl=256: check_regs: incorrect ZA state
>>>>
>>>> 		=== gdb Summary ===
>>>>
>>>> # of expected passes		12751
>>>> # of unexpected failures	2
>>>> # of unresolved testcases	11
>>>>
>>>> ---
>>>>
>>>> I wonder if it has anything to do with the fact we first invoke the gdb_caching_proc
>>>> allow_aarch64_sme_tests which in turn calls the gdb_caching_proc aarch64_initialize_sme_information.
>>>>
>>>> Both call gdb_exit, because they run separate sets of tests. Maybe that gets recursive.
>>>>
>>>> This was uncovered now because sme tests are only executed in emulation, and that doesn't
>>>> get tested as often as we'd like.
>>>>
>>>> Any thoughts?
>>>
>>> I'd start with adding some logging in gdb_cache_maybe_gdb_exit
>>> (lib/cache.exp) like:
>>>
>>>   proc gdb_cache_maybe_gdb_exit { name do_exit } {
>>>       if { !$do_exit } {
>>>   	return
>>>       }
>>>   
>>>       # To track if this proc has been called for NAME we create a
>>>       # global variable.  In gdb_cleanup_globals (see gdb.exp) this
>>>       # global will be deleted when the test has finished.
>>>       set global_name __${name}__cached_gdb_exit_called
>>>       if { ![info exists ::${global_name}] } {
>>>         verbose -log "XXXX: gdb_exit triggered by cache"
>>>   	gdb_exit
>>>   	set ::${global_name} true
>>>       }
>>>   }
>>>
>>> then check to see if this is triggered anywhere that you don't expect it
>>> to.
>>>
>>> I'll keep looking on my end to see if I can spot anything.
>>
>> OK, I see what's going on.
>>
>> In the first test script, aarch64-sme-core-0.exp, we call the caching
>> proc require allow_aarch64_sme_tests, which calls
>> aarch64_initialize_sme_information.  Both of these call gdb_exit, and
>> this fact is recorded in the cache.
>>
>> In the second test script we also call allow_aarch64_sme_tests, but the
>> answer for this is now cached so we invoke gdb_exit (for consistency)
>> and then return the cached answer.  So far, so good.
>>
>> Now, the expectation is that caching procs only run their body the first
>> time they are called, so a future call to allow_aarch64_sme_tests will
>> not call gdb_exit.
>>
>> Later in the second test script though we call aarch64_supports_sve_vl
>> (which is not a caching proc), which then calls
>> aarch64_initialize_sve_information, which is a caching proc.  However,
>> this is the first time that aarch64_initialize_sve_information was
>> called, so we call gdb_exit, which is what causes the problem...
>>
>> The quick fix is to call aarch64_initialize_sve_information before the
>> test is started... but that doesn't feel like a great solution.
>>
>> I'm still trying to work out if there's a better way to fix this.
>>
>> Thanks,
>> Andrew
>>
> 
> Ah, thanks for the info. I was checking the code flow with the debugging
> output.
> 
> I suppose we could simplify things a bit and group the sve/sme querying
> functions into a single function that gets called in the same order
> everywhere. Say, a scalable extension initialization function.
> 
> That might leave things open to other folks calling things in interesting
> ways that might break the caching ordering though.
> 
> In any case, I'd be fine to do the grouping thing.

Wait, maybe I confused things a bit. Is the actual problem that we're not
invoking the gdb_caching_proc function directly, and instead are calling
it indirectly through some other function?