From: Andrew Burgess <aburgess@redhat.com>
To: Luis Machado <luis.machado@arm.com>, gdb-patches@sourceware.org
Subject: Re: [PATCH 4/4] gdb/testsuite: track if a caching proc calls gdb_exit or not
Date: Tue, 13 Aug 2024 17:30:10 +0100 [thread overview]
Message-ID: <87bk1wxu5p.fsf@redhat.com> (raw)
In-Reply-To: <67150769-8f37-4457-ab8e-7f4910bc449f@arm.com>
Luis Machado <luis.machado@arm.com> writes:
> On 8/8/24 15:50, Andrew Burgess wrote:
>> Luis Machado <luis.machado@arm.com> writes:
>>
>>> On 8/8/24 11:50, Luis Machado wrote:
>>>> On 8/8/24 11:20, Luis Machado wrote:
>>>>> On 8/7/24 15:31, Andrew Burgess wrote:
>>>>>> 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
>>>>>>
>>>>>> Luis,
>>>>>>
>>>>>> Could you please test the patch below to see if this fixes the issues
>>>>>> you are seeing. This is also running through local testing at my side,
>>>>>> but I thought I'd get your feedback early.
>>>>>>
>>>>>> Thanks,
>>>>>> Andrew
>>>>>>
>>>>>
>>>>> Well, it's one of those things I guess. I saw some errors the first time I tried the patch, but then
>>>>> I couldn't reproduce it anymore. So far it's been running pretty smoothly for both parallel and
>>>>> serialized runs. So I'd say this patch does the job and we should push it.
>>>>> Thanks for putting it together.
>>>>>
>>>>> I'll do a complete run overnight just to make sure, but it will take a little bit before I can report
>>>>> it.
>>>>
>>>> Of course, a short while after sending this, I managed to reproduce the error.
>>>>
>>>> I'm running the following:
>>>>
>>>> make check-gdb TESTS=gdb.arch/*.exp -j$(nproc). Let me fetch some more information.
>>>
>>> It seems we're hitting the same situation with aarch64_initialize_sve_information via aarch64_supports_sve_vl,
>>> which causes the testsuite to call gdb_exit.
>>>
>>> It is as you described, it is the first time we're running gdb.arch/aarch64-sme-core-2.exp, so we go through
>>> caching etc.
>>>
>>> ---
>>>
>>> Running builds/binutils-gdb/gdb/testsuite/../../../../repos/binutils-gdb/gdb/testsuite/gdb.arch/aarch64-sme-core-2.exp ...
>>> gdb_caching_proc allow_aarch64_sve_tests caused gdb_exit to be called
>>> stack trace is Stack trace:
>>> gdb_cache_maybe_gdb_exit proc_name='allow_aarch64_sve_tests' cache_name='unix/allow_aarch64_sve_tests'
>>> gdb_do_cache name='allow_aarch64_sve_tests' args=''
>>> allow_aarch64_sve_tests
>>
>> This makes sense assuming that this is not the first time
>> `allow_aarch64_sve_tests` was called in this test run. This looks like
>> its using the previously cached result.
>>
>> If all had gone as expected then this should have marked `gdb_exit` as
>> having been called for both `allow_aarch64_sve_tests` and
>> `aarch64_initialize_sve_information`, though given what happens below I
>> guess that the marker for `aarch64_initialize_sve_information` isn't
>> being created correctly.
>>
>> You could try applying this patch:
>>
>> ### START ###
>>
>> diff --git a/gdb/testsuite/lib/cache.exp b/gdb/testsuite/lib/cache.exp
>> index 7e1eae9259e..d6027b352f1 100644
>> --- a/gdb/testsuite/lib/cache.exp
>> +++ b/gdb/testsuite/lib/cache.exp
>> @@ -98,6 +98,7 @@ proc gdb_cache_maybe_gdb_exit { proc_name cache_name } {
>> set ::${global_name} true
>>
>> foreach other_name $gdb_data_cache(${cache_name},also_called) {
>> + verbose -log " gdb_caching_proc $other_name also called exit"
>> set global_name __${other_name}__cached_gdb_exit_called
>> set ::${global_name} true
>> }
>> @@ -110,6 +111,8 @@ proc gdb_do_cache {name args} {
>> global gdb_data_cache objdir
>> global GDB_PARALLEL
>>
>> + verbose -log "gdb_do_cache: $name ( $args )"
>> +
>> # Normally, if we have a cached value, we skip computation and return
>> # the cached value. If set to 1, instead don't skip computation and
>> # verify against the cached value.
>>
>> ### END ###
>>
>> which will log the "other" caching procs that are recorded as having
>> been called.
>>
>> Also, if you are running `make -j...." then you can look into the cache
>> files which will be 'gdb/testsuite/cache/unix/allow_aarch64_sve_tests'
>> and 'gdb/testsuite/cache/unix/aarch64_initialize_sve_information' as
>> this should also include the information about the nested caching proc
>> structure.
>>
>>>
>>> gdb_caching_proc allow_aarch64_sme_tests caused gdb_exit to be called
>>> stack trace is Stack trace:
>>> gdb_cache_maybe_gdb_exit proc_name='allow_aarch64_sme_tests' cache_name='unix/allow_aarch64_sme_tests'
>>> gdb_do_cache name='allow_aarch64_sme_tests' args=''
>>> allow_aarch64_sme_tests
>>>
>>> get_compiler_info: gcc-13-2-0
>>> Executing on host: gcc -fno-stack-protector -fdiagnostics-color=never -g3 -march=armv8.5-a+sve -c -g -o builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-20.o builds/binutils-gdb/gdb/testsuite/../../../../repos/binutils-gdb/gdb/testsuite/gdb.arch/aarch64-sme-core.c (timeout = 300)
>>> builtin_spawn -ignore SIGHUP gcc -fno-stack-protector -fdiagnostics-color=never -g3 -march=armv8.5-a+sve -c -g -o builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-20.o builds/binutils-gdb/gdb/testsuite/../../../../repos/binutils-gdb/gdb/testsuite/gdb.arch/aarch64-sme-core.c
>>> Executing on host: gcc -fno-stack-protector builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-20.o -fdiagnostics-color=never -g3 -march=armv8.5-a+sve -g -lm -o builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-2 (timeout = 300)
>>> builtin_spawn -ignore SIGHUP gcc -fno-stack-protector builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-20.o -fdiagnostics-color=never -g3 -march=armv8.5-a+sve -g -lm -o builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-2
>>> builtin_spawn builds/binutils-gdb/gdb/testsuite/../../gdb/gdb -nw -nx -q -iex set height 0 -iex set width 0 -data-directory builds/binutils-gdb/gdb/data-directory
>>> (gdb) set height 0
>>> (gdb) set width 0
>>> (gdb) dir
>>> Reinitialize source path to empty? (y or n) y
>>> Source directories searched: $cdir:$cwd
>>> (gdb) dir builds/binutils-gdb/gdb/testsuite/../../../../repos/binutils-gdb/gdb/testsuite/gdb.arch
>>> Source directories searched: builds/binutils-gdb/gdb/testsuite/../../../../repos/binutils-gdb/gdb/testsuite/gdb.arch:$cdir:$cwd
>>> (gdb) kill
>>> The program is not being run.
>>> (gdb) file builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-2
>>> Reading symbols from builds/binutils-gdb/gdb/testsuite/outputs/gdb.arch/aarch64-sme-core-2/aarch64-sme-core-2...
>>> (gdb) gdb_caching_proc aarch64_initialize_sve_information caused gdb_exit to be called
>>> stack trace is Stack trace:
>>> gdb_cache_maybe_gdb_exit proc_name='aarch64_initialize_sve_information' cache_name='unix/aarch64_initialize_sve_information'
>>> gdb_do_cache name='aarch64_initialize_sve_information' args=''
>>> aarch64_initialize_sve_information
>>> aarch64_supports_sve_vl length='16'
>>> test_sme_core_file id_start='50' id_end='74'
>>
>> This should have been prevented by the earlier allow_aarch64_sve_tests
>> call. Either we failed to correctly spot the relationship between the
>> two caching procs, or we're failing to mark this second one as having
>> been called for some reason...
>>
>> I think we need more data to try and debug this...
>
> I did some more debugging on this, and I think I see what's going on here. I haven't
> checked the flow in detail yet, but hopefully it will ring some bells.
>
> My theory is that your patch's logic is sane, but we're hitting concurrency issues when
> running things in parallel, or parallel enough. For instance, I consistently hit issues when
> using -j4, but I can't hit it with anything below -j4.
>
> I added a couple debugging statements in gdb_do_cache, at the end within the if {[info exists GDB_PARALLEL]} block.
>
> The statements check if the $cache_filename exists and what the contents are, before we rename
> $cache_filename.[pid] to $cache_filename, essentially overwriting the old cache file.
>
> What I saw was the following:
>
> ---
>
> gdb_do_cache: aarch64_initialize_sve_information ( )
> gdb_caching_proc aarch64_initialize_sve_information caused gdb_exit to be called
> Stack trace:
> gdb_cache_maybe_gdb_exit proc_name='aarch64_initialize_sve_information' cache_name='unix/aarch64_initialize_sve_information'
> gdb_do_cache name='aarch64_initialize_sve_information' args=''
> aarch64_initialize_sve_information
> gdb_real__allow_aarch64_sve_tests
> allow_aarch64_sve_tests
>
> XXXX: File builds/binutils-gdb/gdb/testsuite/cache/unix/allow_aarch64_sve_tests already exists before rename.
> XXXX: Old contents: 1 true aarch64_initialize_sve_information
> XXXX: New contents: 1 true {}
> gdb_caching_proc allow_aarch64_sve_tests caused gdb_exit to be called
> Stack trace:
> gdb_cache_maybe_gdb_exit proc_name='allow_aarch64_sve_tests' cache_name='unix/allow_aarch64_sve_tests'
> gdb_do_cache name='allow_aarch64_sve_tests' args=''
> allow_aarch64_sve_tests
>
> ---
>
> So we replace a cache file that contains more information with a copy that has less information.
>
> Eventually we call aarch64_initialize_sve_information again, via a different function, and things go bad.
>
> I'm guessing the logic of updating the cache files needs to be atomic, and we're having some timing issues
> where two (or more) tests try to update the same file and we end up losing information.
Thanks for doing the leg work on this. The information you provided is
spot on, and it was indeed a timing issue as you predicted. Here's
what's happening:
In thread #1 we call 'allow_aarch64_sme_tests', there's no cache file
yet we eval the body, this calls 'aarch64_initialize_sme_information'.
So we try to create two cache files in this order:
unix/aarch64_initialize_sme_information
value: ... whatever ...
exit_called?: true
also_called: {}
unix/allow_aarch64_sme_tests
value: ... whatever ...
exit_called?: true
also_called: aarch64_initialize_sme_information
In thread #2 we also call 'allow_aarch64_sme_tests', however, if we
manage to land after the first cache file was created but before the
second file was created then we pick up the cached result for
'aarch64_initialize_sme_information'.
And this is where my bug was: I didn't add
'aarch64_initialize_sme_information' to the also_called list for a
caching proc if we managed to find a cached value. As a result, the
thread #2 cache file looked like this:
unix/allow_aarch64_sme_tests
value: ... whatever ...
exit_called?: true
also_called: {}
which then overwrote the first cache file (atomically).
A later test would call 'allow_aarch64_sme_tests' and then separately
call 'aarch64_initialize_sme_information'. Due to the corrupted cache
file calling 'allow_aarch64_sme_tests' would not mark
'aarch64_initialize_sme_information' as having been called. So when we
separately call 'aarch64_initialize_sme_information' gdb_exit would be
called which broke the test.
The fix, of course, is to ensure that when we get a cache hit we still
record the called function as being something that is "also called".
I have a new patch below (discard the previous patch I sent) which I
think should resole the problems you're having. I'm still running the
full tests on my end, but initial (limited) testing looks good.
Thanks,
Andrew
---
commit 7384f334613a548bc26eaf238650076537c9b8fb
Author: Andrew Burgess <aburgess@redhat.com>
Date: Wed Aug 7 14:51:06 2024 +0100
gdb/testsuite: track nested caching proc calls
It was pointed out in this email:
https://inbox.sourceware.org/gdb-patches/97973506-79f4-4216-9c0b-57401b3933f5@arm.com
that this commit:
commit 0726729d344fecf98f8d138e688e77201cc3cece
Date: Mon Jun 3 13:56:54 2024 +0100
gdb/testsuite: track if a caching proc calls gdb_exit or not
had broken some AArch64 tests.
What is going on is that there are two caching procs:
allow_aarch64_sme_tests
aarch64_initialize_sme_information
the allow_aarch64_sme_tests proc makes a call to
aarch64_initialize_sme_information, but
aarch64_initialize_sme_information is also called from other
non-caching procs, like aarch64_supports_sme_svl.
Both of the caching procs mentioned above compile and run a helper
program, and both of them call gdb_exit.
After the above commit, the first call to any caching proc, the body
of which calls gdb_exit, will result in a gdb_exit call even if the
body is not executed and the result is fetched from the cache.
What was observed is that in the first test script
allow_aarch64_sme_tests is called, the body of this caching proc is
run which calls gdb_exit. Then allow_aarch64_sme_tests calls
aarch64_initialize_sme_information, the body of which is run and
gdb_exit is called again. The results from both procs are added to
the cache.
In the next test script allow_aarch64_sme_tests is called. This
results in a cache hit, but gdb_exit is also called as this is the
first call in this second test script.
Later in the test script aarch64_supports_sme_svl is called which
calls aarch64_initialize_sme_information. As this is the first call
to aarch64_initialize_sme_information in this second test
script (remember the body of allow_aarch64_sme_tests was never run)
then gdb_exit is called. This call to gdb_exit is new after the above
commit and is unexpected.
I think the idea behind the above commit is still sound. If the call
to allow_aarch64_sme_tests was removed from the second test script
then we would want the extra gdb_exit call as this would expose a real
bug in the test. The problem is that after the above commit the
nested nature of the caching proc calls becomes important: a call to
allow_aarch64_sme_tests should mean that we've also called
aarch64_initialize_sme_information, and that relationship isn't
currently captured.
So in this commit I'm adding another field to the global
gdb_data_cache (in lib/cache.exp). This new field is 'also_called'.
For every caching proc we populate this field with a list of names,
these are the names of any nested caching procs that are called when
the body of a caching proc is executed.
Now when we get a cache hit in gdb_data_cache we mark every proc in
the 'also_called' list as having been called. This means that further
calls to these procs will no longer trigger a gdb_exit call.
diff --git a/gdb/testsuite/lib/cache.exp b/gdb/testsuite/lib/cache.exp
index 092b7f136e8..ca3dca22f96 100644
--- a/gdb/testsuite/lib/cache.exp
+++ b/gdb/testsuite/lib/cache.exp
@@ -59,13 +59,38 @@ proc gdb_exit_called { args } {
set ::gdb_exit_called true
}
-# 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.
+# While calling the implementation of a caching proc, that
+# implementation might itself call additional caching procs. We need
+# to track all of the nested caching procs that are called and we do
+# that in this list which is a list containing the names of any nested
+# caching procs that are called.
-proc gdb_cache_maybe_gdb_exit { name do_exit } {
+set gdb_nested_caching_proc_calls {}
+
+# Called before returning from gdb_do_cache. NAME is the name of the
+# caching proc that was called.
+#
+# When DO_EXIT is true then this proc should call gdb_exit before
+# returning, otherwise gdb_exit is not called.
+#
+# ALSO_CALLED is a list of the names all the nested caching procs that
+# the proc NAME called. This proc appends NAME as well as everything
+# in ALSO_CALLED to the global GDB_NESTED_CACHING_PROC_CALLS, this
+# aids in tracking recursive caching proc calls.
+
+proc gdb_cache_maybe_gdb_exit { name do_exit also_called } {
+
+ # Record all the procs that have been called, but only if the exit
+ # trace is in place (this is done in gdb_do_cache) and indicates
+ # that we are in data gathering mode.
+ if { [info exists ::gdb_exit_trace_in_place] } {
+ set ::gdb_nested_caching_proc_calls \
+ [list {*}$::gdb_nested_caching_proc_calls $name {*}$also_called]
+ }
+
+ # The cache 'exit' entry will be true if this caching proc, or any
+ # caching proc that is recursively called from this caching proc,
+ # called exit.
if { !$do_exit } {
return
}
@@ -76,7 +101,15 @@ proc gdb_cache_maybe_gdb_exit { name do_exit } {
set global_name __${name}__cached_gdb_exit_called
if { ![info exists ::${global_name}] } {
gdb_exit
+ verbose -log "gdb_caching_proc $name caused gdb_exit to be called"
set ::${global_name} true
+ verbose -log " gdb_caching_proc $name marked as called"
+
+ foreach other_name $also_called {
+ verbose -log " gdb_caching_proc $other_name marked as called"
+ set global_name __${other_name}__cached_gdb_exit_called
+ set ::${global_name} true
+ }
}
}
@@ -86,6 +119,8 @@ proc gdb_do_cache {name args} {
global gdb_data_cache objdir
global GDB_PARALLEL
+ verbose -log "gdb_do_cache: $name ( $args )"
+
# Normally, if we have a cached value, we skip computation and return
# the cached value. If set to 1, instead don't skip computation and
# verify against the cached value.
@@ -107,9 +142,10 @@ proc gdb_do_cache {name args} {
if {[info exists gdb_data_cache(${cache_name},value)]} {
set cached_value $gdb_data_cache(${cache_name},value)
set cached_exit $gdb_data_cache(${cache_name},exit)
+ set cached_also_called $gdb_data_cache(${cache_name},also_called)
verbose "$name: returning '$cached_value' from cache" 2
if { $cache_verify == 0 } {
- gdb_cache_maybe_gdb_exit $name $cached_exit
+ gdb_cache_maybe_gdb_exit $name $cached_exit $cached_also_called
return $cached_value
}
set is_cached 1
@@ -123,11 +159,13 @@ proc gdb_do_cache {name args} {
close $fd
set gdb_data_cache(${cache_name},value) [lindex $content 0]
set gdb_data_cache(${cache_name},exit) [lindex $content 1]
+ set gdb_data_cache(${cache_name},also_called) [lindex $content 2]
set cached_value $gdb_data_cache(${cache_name},value)
set cached_exit $gdb_data_cache(${cache_name},exit)
+ set cached_also_called $gdb_data_cache(${cache_name},also_called)
verbose "$name: returning '$cached_value' from file cache" 2
if { $cache_verify == 0 } {
- gdb_cache_maybe_gdb_exit $name $cached_exit
+ gdb_cache_maybe_gdb_exit $name $cached_exit $cached_also_called
return $cached_value
}
set is_cached 1
@@ -164,9 +202,29 @@ proc gdb_do_cache {name args} {
set old_gdb_exit_called $::gdb_exit_called
set ::gdb_exit_called false
+ # As with the exit tracking above we also need to track any nested
+ # caching procs that this proc might call. To do this we backup
+ # the current global list of nested caching proc calls and reset
+ # the global back ot the empty list. As nested caching procs are
+ # called their names are added to the global list, see
+ # gdb_cache_maybe_gdb_exit for where this is done.
+ set old_gdb_nested_caching_proc_calls $::gdb_nested_caching_proc_calls
+ set ::gdb_nested_caching_proc_calls {}
+
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
+ set gdb_data_cache(${cache_name},also_called) \
+ [lsort -unique $::gdb_nested_caching_proc_calls]
+
+ # Now that the actual implementation of this caching proc has been
+ # executed the gdb_nested_caching_proc_calls global will contain
+ # the names of any nested caching procs that were called. We
+ # append this new set of names onto the set of names we backed up
+ # above.
+ set ::gdb_nested_caching_proc_calls \
+ [list {*}$old_gdb_nested_caching_proc_calls \
+ {*}$::gdb_nested_caching_proc_calls]
# See comment above where OLD_GDB_EXIT_CALLED is set: if
# GDB_EXIT_CALLED was previously true then this is a recursive
@@ -183,6 +241,7 @@ proc gdb_do_cache {name args} {
trace remove execution gdb_exit enter gdb_exit_called
unset ::gdb_exit_trace_in_place
set ::gdb_exit_called false
+ set ::gdb_nested_caching_proc_calls {}
}
# If a value being stored in the cache contains a newline then
@@ -196,6 +255,7 @@ proc gdb_do_cache {name args} {
if { $cache_verify == 1 && $is_cached == 1 } {
set computed_value $gdb_data_cache(${cache_name},value)
set computed_exit $gdb_data_cache(${cache_name},exit)
+ set computed_also_called $gdb_data_cache(${cache_name},also_called)
if { $cached_value != $computed_value } {
error [join [list "Inconsistent value results for $cache_name:"
"cached: $cached_value vs. computed: $computed_value"]]
@@ -204,6 +264,10 @@ proc gdb_do_cache {name args} {
error [join [list "Inconsistent exit results for $cache_name:"
"cached: $cached_exit vs. computed: $computed_exit"]]
}
+ if { $cached_also_called != $computed_also_called } {
+ error [join [list "Inconsistent also_called results for $cache_name:"
+ "cached: $cached_also_called vs. computed: $computed_also_called"]]
+ }
}
if {[info exists GDB_PARALLEL]} {
@@ -213,10 +277,12 @@ proc gdb_do_cache {name args} {
set fd [open $cache_filename.[pid] w]
puts $fd $gdb_data_cache(${cache_name},value)
puts $fd $gdb_data_cache(${cache_name},exit)
+ puts $fd $gdb_data_cache(${cache_name},also_called)
close $fd
file rename -force -- $cache_filename.[pid] $cache_filename
}
- gdb_cache_maybe_gdb_exit $name $gdb_data_cache(${cache_name},exit)
+ gdb_cache_maybe_gdb_exit $name $gdb_data_cache(${cache_name},exit) \
+ $gdb_data_cache(${cache_name},also_called)
return $gdb_data_cache(${cache_name},value)
}
next prev parent reply other threads:[~2024-08-13 16:31 UTC|newest]
Thread overview: 32+ messages / expand[flat|nested] mbox.gz Atom feed top
2024-06-03 18:16 [PATCH 0/4] gdb/testsuite: remove can_spawn_for_attach_1 Andrew Burgess
2024-06-03 18:16 ` [PATCH 1/4] gdb/testsuite: remove trailing \r from rust_llvm_version result Andrew Burgess
2024-06-04 13:51 ` Tom Tromey
2024-06-05 9:20 ` Andrew Burgess
2024-06-03 18:16 ` [PATCH 2/4] gdb/testsuite: improve with_override Andrew Burgess
2024-06-03 18:16 ` [PATCH 3/4] gdb/testsuite: restructure gdb_data_cache (lib/cache.exp) Andrew Burgess
2024-06-03 18:16 ` [PATCH 4/4] gdb/testsuite: track if a caching proc calls gdb_exit or not Andrew Burgess
2024-08-07 6:05 ` Luis Machado
2024-08-07 9:16 ` Andrew Burgess
2024-08-07 10:00 ` Andrew Burgess
2024-08-07 10:08 ` Luis Machado
2024-08-07 10:12 ` Luis Machado
2024-08-07 12:45 ` Andrew Burgess
2024-08-07 14:31 ` Andrew Burgess
2024-08-07 18:35 ` Luis Machado
2024-08-08 10:20 ` Luis Machado
2024-08-08 10:50 ` Luis Machado
2024-08-08 11:08 ` Luis Machado
2024-08-08 14:50 ` Andrew Burgess
2024-08-09 11:29 ` Luis Machado
2024-08-13 16:30 ` Andrew Burgess [this message]
2024-08-14 13:06 ` Luis Machado
2024-08-14 17:00 ` Andrew Burgess
2024-08-15 6:03 ` Luis Machado
2024-08-20 15:25 ` Andrew Burgess
2024-06-04 9:06 ` [PATCH 0/4] gdb/testsuite: remove can_spawn_for_attach_1 Andrew Burgess
2024-06-05 13:27 ` [PATCHv2 0/2] " Andrew Burgess
2024-06-05 13:27 ` [PATCHv2 1/2] gdb/testsuite: restructure gdb_data_cache (lib/cache.exp) Andrew Burgess
2024-06-05 13:27 ` [PATCHv2 2/2] gdb/testsuite: track if a caching proc calls gdb_exit or not Andrew Burgess
2024-07-28 8:54 ` [PUSHED 0/2] gdb/testsuite: remove can_spawn_for_attach_1 Andrew Burgess
2024-07-28 8:54 ` [PUSHED 1/2] gdb/testsuite: restructure gdb_data_cache (lib/cache.exp) Andrew Burgess
2024-07-28 8:54 ` [PUSHED 2/2] gdb/testsuite: track if a caching proc calls gdb_exit or not Andrew Burgess
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=87bk1wxu5p.fsf@redhat.com \
--to=aburgess@redhat.com \
--cc=gdb-patches@sourceware.org \
--cc=luis.machado@arm.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox