Re: [PATCH 2/2 ] PowerPC: fix for gdb.reverse/finish-precsave.exp and gdb.reverse/finish-reverse.exp

[Simon Marchi <simark@simark.ca>]

On 3/27/23 19:59, Carl Love wrote:
> Simon:
> 
> On Sat, 2023-03-25 at 08:39 -0400, Simon Marchi wrote:
>>
> 
> <snip>
> 
>>>
>>> Yes, there was a regression failure.  The following was committed
>>> to
>>> fix the reported regression issues.
>>>
>>> https://sourceware.org/pipermail/gdb-patches/2023-March/198139.html 
>>
>> I also saw these regressions, but they are fixed (by that
>> commit).  This
>> seems like a different thing.
>>
>>> Are you testing with this fix?
>>
>> Yes, and I just tried with today's master, same thing.
>>
>>> I don't normally run the tests with --target_board=native-gdbserver 
>>> but
>>> I did try that and it seemed to work for me.  Note I had to also
>>> specify GDBFLAGS to get the test to run.  Specifically, I used the
>>> command:
>>>
>>> make check TESTS="gdb.reverse/finish-reverse-
>>> next.exp"  RUNTESTFLAGS="GDBFLAGS=' ' --target_board=native-
>>> gdbserver "
>>
>> That's odd, I never had to do that thing with GDBFLAGS.  What happens
>> when you don't specify it?
> 
> When I run on Power 10 without GDBFLAGS I get the message:
> 
>    make check TESTS="gdb.reverse/finish-reverse-next.exp"  RUNTESTFLAGS=" --target_board=native-gdbserver " 
> 
>    <snip>
> 
>    ERROR: tcl error sourcing board description file for target /home.../gdb/testsuite/boards/gdbserver-base.exp.
>    can't read "GDBFLAGS": no such variable
>    can't read "GDBFLAGS": no such variable
>        while executing
>    "set GDBFLAGS "${GDBFLAGS} -iex \"set auto-connect-native-target off\"""
>        (file "/home.../gdb/testsuite/boards/gdbserver-base.exp" line 35)
>        invoked from within
>    "source /home.../gdb/testsuite/boards/gdbserver-base.exp"
>        ("uplevel" body line 1)
>        invoked from within
>    "uplevel #0 source /home/.../gdb/testsuite/boards/gdbserver-base.exp"
>        invoked from within
>    "catch "uplevel #0 source $filename" error"
>    make[5]: *** [Makefile:1829: check-DEJAGNU] Error 1
> 
>>
>> For reference, here's an example failure:
>>
>> 147 reverse-next^M
>> 148 81        b = 5;^M 
>> 149 (gdb) FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 1
>> LEP from function body
>> 150 reverse-next^M
>> 151 80        a = 1;^M
>> 152 (gdb) FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 2
>> at b = 5, from function body
> 
> You didn't mention what platform you are running on, but I am guessing
> X86.  I created a little run script to run the test with and without
> the --target-board argument on Power 10.  Here is my script.
> 
>     more check-reverse
> 
>    echo " "
>    echo reverse.exp
>    rm testsuite/gdb.log
>    make check RUNTESTFLAGS='GDB=/home/carll/bin/gdb   gdb.reverse/finish-reverse-next.exp   ' > out-reverse-next
>    grep "of expected passes" testsuite/gdb.log
>    grep "of unexpected failures" testsuite/gdb.log
>    mv testsuite/gdb.log testsuite/gdb.log-reverse-next
> 
> 
>    echo " "
>    echo reverse.exp
>    rm testsuite/gdb.log
>    make check TESTS="gdb.reverse/finish-reverse-next.exp"  RUNTESTFLAGS="GDBFLAGS=' ' --target_board=native-gdbserver "  > out-reverse-next-gdbserver
>    grep "of expected passes" testsuite/gdb.log
>    grep "of unexpected failures" testsuite/gdb.log
>    mv testsuite/gdb.log testsuite/gdb.log-reverse-next-gdbserver
> 
> So, assuming you are on X86, I copied the script to my X86 box and tried it out there as well.
> 
> I ran the script in the top of the build directory.  For the first test
> without --target_board I get the results:
> 
>    Using /usr/share/dejagnu/config/unix.exp as generic interface file for target.
>       Using /.../gdb/testsuite/config/unix.exp as tool-and-target-specific interface file.
>       Running /.../binutils-gdb-finish-precsave-PPC-Only/gdb/testsuite/gdb.reverse/finish-reverse-next.exp ...
> 
>                    === gdb Summary ===
> 
>       # of expected passes            40
>       gdb version  14.0.50.20230324-git -nw -nx -iex "set height 0" -iex "set width 0"
> 
>                    === gdb Summary ===
> 
>       # of expected passes            40
>       gdb version  14.0.50.20230324-git -nw -nx -iex "set height 0" -iex "set width 0"
> 
> The second test with the --target_board I get a number of failures and
> never actually get to run the finish-reverse-next test.  The output I
> see is:
> 
>    Running target native-gdbserver
>    Using /usr/share/dejagnu/baseboards/native-gdbserver.exp as board description file for target.
>    Using /home/carll/GDB/binutils-gdb-finish-precsave-PPC-Only/gprofng/testsuite/config/default.exp as tool-and-target-specific interface file.
>    Running /home/carll/GDB/binutils-gdb-finish-precsave-PPC-Only/gprofng/testsuite/gprofng.display/display.exp ...
>    ERROR: comparison of results in mttest failed
>    ERROR: comparison of results in mttest failed
>    ERROR: comparison of results in synprog failed
>    ERROR: comparison of results in synprog failed
> 
>    		=== gprofng Summary ===
> 
>    # of unresolved testcases       4
>    # of unsupported tests          1
>    make[4]: Leaving directory '/home/.../gprofng'
>    make[3]: Leaving directory '/home/.../gprofng'
>    make[2]: Leaving directory '/home/.../gprofng'
>    make[1]: Leaving directory '/home/...'
> 
> So, tried changing the paths in the script from gdb/testscript to
> testscript and then ran the script in the subdirectory gdb.  When I do
> that, I get the same results for the first test as I saw befor.  Now,
> the second test with --target_board runs and I get the following
> output:
> 
>    ...
>    Using /home/.../binutils-gdb-finish-precsave-PPC-Only/gdb/testsuite/boards/../boards/gdbserver-base.exp as board de
>    scription file for target.
>    Using /home/.../binutils-gdb-finish-precsave-PPC-Only/gdb/testsuite/boards/../boards/local-board.exp as board description file for target.
>    Using /home/carll/GDB/build-finish-precsave-PPC-Only/gdb/testsuite/../../../binutils-gdb-finish-precsave-PPC-Only/gdb/testsuite/config/gdbserver.exp as tool-and-target-specifi
>    c interface file.
>    Running /home/carll/GDB/build-finish-precsave-PPC-Only/gdb/testsuite/../../../binutils-gdb-finish-precsave-PPC-Only/gdb/testsuite/gdb.reverse/finish-reverse-next.exp ...
>    FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 1 LEP from function body
>    FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 2 at b = 5, from function body
>    FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 1 GEP call from function body
>    FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 2 at b = 50 from function body
> 
>    		=== gdb Summary ===
> 
>    # of expected passes		36
>    # of unexpected failures	4
> 
> which appears to match the failures you saw.  Why the --target-board
> argument seems to make a difference is a mystery to me at this point!!

Ahh, that must be it.  You were running the make check at the top-level.
We pretty much always run it inside gdb/ or gdb/testsuite/.

> I can see what what happens...  So, when you do a reverse-finish, gdb
> stops at the branch instruction for the function call.  Then when you
> do a reverse-next and gdb stops at the beginning of the same source
> code line.  This is the expected behavior for gdb per the discussion we
> had a few months ago.  Hence in the test file we have:
> 
>    # The reverse-finish command should stop on the function call instruction                              
>    # which is the last instruction in the source code line.  A reverse-next                               
>    # instruction should then stop at the first instruction in the same source                             
>    # code line.  Another revers-next instruction stops at the previous source                             
>    # code line.                                                                                           
>    gdb_test "reverse-finish" ".*function1 \\(a, b\\);   // CALL VIA LEP.*" \
>        "reverse-finish function1 LEP call from function body"
>    gdb_test "reverse-next" ".*function1 \\(a, b\\);   // CALL VIA LEP.*" \
>        "reverse next 1 LEP from function body"
>    gdb_test "reverse-next" ".*b = 5;.*" \
>        "reverse next 2 at b = 5, from function body"
> 
> The test is looking to see that it is at source line function1 (a, b)
> after both reverse-finish and the reverse-next commands.
> 
> Looking in the output file for the run with and without the --target-
> board on X86, we see:
> 
> without the target board specified:
> 
> 
>    step
>    function1 (a=1, b=5) at /home/carll/.../gdb/testsuite/gdb.reverse/finish-reverse-next.c:51
>    51        int ret = 0;
>    (gdb) PASS: gdb.reverse/finish-reverse-next.exp: step test 1
> 
>    reverse-finish
>    Run back to call of #0  function1 (a=1, b=5) at /home/carll/..../gdb/testsuite/gdb.reverse/finish-reverse-next.c:51
>    0x00005555555551cb in main (argc=1, argv=0x7fffffffde88) at /home/carll/.../gdb/testsuite/gdb.reverse/finish-reverse-next.c:83^M
>    83        function1 (a, b);   // CALL VIA LEP
>    (gdb) PASS: gdb.reverse/finish-reverse-next.exp: reverse-finish function1 LEP call from function body
> 
>    reverse-next
>    83        function1 (a, b);   // CALL VIA LEP
>    (gdb) PASS: gdb.reverse/finish-reverse-next.exp: reverse next 1 LEP from function body reverse-next
>    81        b = 5;
> 
>    reverse-continue
>    Continuing.
> 
>    No more reverse-execution history.
> 
>    We see the reverse-finish and the reverse-next both stop at function1
>    (a, b) as expected.
> 
>    But with  --target-board, we see:
> 
>    step
>    function1 (a=1, b=5) at /home/carll/..../gdb/testsuite/gdb.reverse/finish-reverse-next.c:51
>    51        int ret = 0;
>    (gdb) PASS: gdb.reverse/finish-reverse-next.exp: step test 1
> 
>    reverse-finish
>    Run back to call of #0  function1 (a=1, b=5) at /home/carll/..../gdb/testsuite/gdb.reverse/finish-reverse-next.c:51
>    main (argc=1, argv=0x7fffffffde88) at /home/carll/.../gdb/testsuite/gdb.reverse/finish-reverse-next.c:83
>    83        function1 (a, b);   // CALL VIA LEP
>    (gdb) PASS: gdb.reverse/finish-reverse-next.exp: reverse-finish function1 LEP call from function body
> 
>    reverse-next
>    81        b = 5;
>    (gdb) FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 1 LEP from function body
> 
>    reverse-next
>    80        a = 1;
>    (gdb) FAIL: gdb.reverse/finish-reverse-next.exp: reverse next 2 at b = 5, from function body
> 
>    reverse-continue
>    Continuing.
> 
> It appears the reverse-finish stopped at the beginning of the source
> line, not the function call as expected, because the reverse-next stops
> at the previous source line not the same source line as expected.  I
> think it would only do that if GDB was at the beginning of the source
> line after the reverse-finish command is done.  The issue "appears to
> be" that the reverse-finish command behaves differently with the --
> target_board???
> 
> I am at a loss as to why using gdbserver causes this change in the
> behavior of the test.  Unfortunately, I have never looked at how
> gdbserver works so I don't know what the issue might be.  
> 
> I tried rewinding my gdb tree on X86 to the commit
>   
> commit 334d405c2ac395fca67b952affb20893002d969f (HEAD)
> Author: Carl Love <cel@us.ibm.com>
> Date:   Wed Mar 1 11:45:43 2023 -0500
> 
>     Move step_until procedure
>     ....
> 
> which is the commit before the fix for the reverse-finish command on
> Power10.  Note, the finish-reverse-next is a new test that is added
> with the Power 10 reverse-finish command fix.  I had to make a copy of 
> finish-reverse-next.c and finish-reverse-next.exp before rewinding the
> source tree and restoring them after the rewind.  I rebuilt gdb without
> the PowerPC fix.  When I run my script I see the exact same behavior on
> X86, i.e. the first test works fine, the second test fails.  So, it
> looks to me like the issue is independent of the changes made in my
> commit for Power10.  
> 
> It would probably be good if you can try to reproduce the failure
> without the Power10 fix.  Note, you do need the patch to move the
> step_until proceedure so when you restore the test it will work.  The
> test is dependent on that commit.
> 
> Let me know if you can verify the test fails without the Power10 fix
> and with --target_board.  
> 
> When I run the above script on Power 10, the first test runs fine and
> is the only test that is run.  The second test results in running a
> whole bunch of tests in addition to finish-reverse-next.  I have to
> search thru the log file to find where the test ran.  No errors are
> reported for the finish-reverse-next test.  But I do see errors in
> other tests.  Actually, the output looks like what I get when I run
> "make check".  I looked to see if I could find an error about the
> arguments that would explain why the test "appears" to ignore the
> request to run one test and runs what appears to be everything.  I
> don't see reported errors or warnings.  I also tried moving the script
> to the gdb build directory/gdb, like what I did on X86, and tweaked the
> paths in the script.  Again, the first test runs just fine and appears
> to be the only test that is run.  The second test seems to actually run
> all of the tests again.  When I look in the log file, again I can see
> where finish-reverse-next ran and doesn't appear to generate any errors
> but I am seeing all these other tests that ran.
> 
> In summary, there seems to be an issue with using the --target_board
> argument.  On X86, the reverse-finish command seems to work a little
> different with and without the --target-board command.  This is
> independent of the Power 10 reverse-finish patch.  On Power 10, the use
> of the --target_board option seems to cause all tests to run not just
> the one requested.  Maybe there is something wrong with the make
> command in the test file that explains the behavior on Power 10??
> Unfortunately, I have not worked on gdbserver so I really have no idea
> what is going on.

Indeed, it just looks like a pre-existing issue that the new test has
uncovered.  Don't worry, it happens all the time in GDB.

I was able to reproduce by hand, and used the "maintenance print
record-instruction" command to print the recorded instructions in both
cases.  In the case of native debugging, these are all the recorded
instructions between the beginning of the function call line to the end
of the recording:

    (gdb) maintenance print record-instruction -9
    Register rdx changed: 140737488346408
[1] Register rip changed: (void (*)()) 0x5555555551a5 <main+40>
    (gdb) maintenance print record-instruction -8
    Register rax changed: 93824992235839
    Register rip changed: (void (*)()) 0x5555555551a8 <main+43>
    (gdb) maintenance print record-instruction -7
    Register rsi changed: 140737488346392
    Register rip changed: (void (*)()) 0x5555555551ab <main+46>
    (gdb) maintenance print record-instruction -6
    Register rdi changed: 1
    Register rip changed: (void (*)()) 0x5555555551ad <main+48>
    (gdb) maintenance print record-instruction -5
    Register rsp changed: (void *) 0x7fffffffdbe0
    8 bytes of memory at address 0x00007fffffffdbd8 changed from: 00 00 00 00 00 00 00 00
[2] Register rip changed: (void (*)()) 0x5555555551af <main+50>
    (gdb) maintenance print record-instruction -4
    Register rsp changed: (void *) 0x7fffffffdbd8
    8 bytes of memory at address 0x00007fffffffdbd0 changed from: 00 00 00 00 00 00 00 00
    Register rip changed: (void (*)()) 0x55555555513f <function1>
    (gdb) maintenance print record-instruction -3
    Register rbp changed: (void *) 0x7fffffffdc00
    Register rip changed: (void (*)()) 0x555555555140 <function1+1>
    (gdb) maintenance print record-instruction -2
    Register rsp changed: (void *) 0x7fffffffdbd0
    Register eflags changed: [ IF ]
    Register rip changed: (void (*)()) 0x555555555143 <function1+4>
    (gdb) maintenance print record-instruction -1
    4 bytes of memory at address 0x00007fffffffdbbc changed from: 00 00 00 00
    Register rip changed: (void (*)()) 0x555555555147 <function1+8>
    (gdb) maintenance print record-instruction 0
    4 bytes of memory at address 0x00007fffffffdbb8 changed from: 00 00 00 00
[3] Register rip changed: (void (*)()) 0x55555555514a <function1+11>

With gdbserver:

    (gdb) maintenance print record-instruction -5
    Register rdx changed: 140737488346600
[1] Register rip changed: (void (*)()) 0x5555555551a5 <main+40>
    (gdb) maintenance print record-instruction -4
    Register rsp changed: (void *) 0x7fffffffdc98
    8 bytes of memory at address 0x00007fffffffdc90 changed from: 00 00 00 00 00 00 00 00
    Register rip changed: (void (*)()) 0x55555555513f <function1>
    (gdb) maintenance print record-instruction -3
    Register rbp changed: (void *) 0x7fffffffdcc0
    Register rip changed: (void (*)()) 0x555555555140 <function1+1>
    (gdb) maintenance print record-instruction -2
    Register rsp changed: (void *) 0x7fffffffdc90
    Register eflags changed: [ PF IF ]
    Register rip changed: (void (*)()) 0x555555555143 <function1+4>
    (gdb) maintenance print record-instruction -1
    4 bytes of memory at address 0x00007fffffffdc7c changed from: 00 00 00 00
    Register rip changed: (void (*)()) 0x555555555147 <function1+8>
    (gdb) maintenance print record-instruction 0
    4 bytes of memory at address 0x00007fffffffdc78 changed from: 00 00 00 00
[3] Register rip changed: (void (*)()) 0x55555555514a <function1+11>

The important points are:

[1] Beginning of function call line
[2] Call instruction
[3] Starting point

We see that there are fewer recorded instructions with gdbserver.
Seeing this, I thought of the range-stepping feature of the remote
protocol.  This allows GDB to tell GDBserver to step a thread as long as
it's within a certain range of PC.  This is useful when stepping over a
source line, to avoid the back and forth of GDB asking GDBserver to step
instructions repeatedly.

If you enable "set debug remote 1" while doing the "step" command, when
connected to GDBserver, you'll see this resumption packet:


  [remote] Sending packet: $vCont;r5555555551a5,5555555551b4:p3b326.3b326;c:p3b326.-1#67

This tells GDBserver to resume the thread 3b326 (thread id in hex),
single-stepping it as long as within those PCs.  Because of that, GDB
never sees the individual steps in that region:

    83        function1 (a, b);   // CALL VIA LEP
       0x00005555555551a5 <+40>:    mov    -0x10(%rbp),%edx
       0x00005555555551a8 <+43>:    mov    -0xc(%rbp),%eax
       0x00005555555551ab <+46>:    mov    %edx,%esi
       0x00005555555551ad <+48>:    mov    %eax,%edi
       0x00005555555551af <+50>:    call   0x55555555513f <function1>

And therefore, GDB's record-full target doesn't record the individual
steps.  The native linux target doesn't use range stepping (it reports
stops for all individual steps).

To confirm the theory, I added a:

   gdb_test "set range-stepping off"

somewhere near the beginning of your test, and it makes the test pass
with native-gdbserver.

If we want recording to work the same with process targets using
range-stepping and those that don't, maybe GDB should avoid using
range-stepping when the record-full target is in effect?

Simon