Bug 24711 - FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 1/0 (unexpected output)
Summary: FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 1/0 (unexpected o...
Status: RESOLVED FIXED
Alias: None
Product: gdb
Classification: Unclassified
Component: gdb (show other bugs)
Version: HEAD
: P2 normal
Target Milestone: ---
Assignee: Not yet assigned to anyone
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-06-21 06:51 UTC by Tom de Vries
Modified: 2019-07-23 08:39 UTC (History)
1 user (show)

See Also:
Host:
Target:
Build:
Last reconfirmed:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Tom de Vries 2019-06-21 06:51:30 UTC
gdb.sum:
...
FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 1 (unexpected output)
FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 0 (unexpected output)
...

gdb.log:
...
PASS: gdb.mi/mi-complete.exp: -info-gdb-mi-command complete
Expecting: ^(2-complete br[^M
]+)?(.*2\^done,completion="br[A-Za-z0-9-]+",matches=\["br[A-Za-z0-9-]+"\],max_completions_reached="1"[^M
]+[(]gdb[)] ^M
[ ]*)
set max-completions 1^M
2-complete br^M
&"set max-completions 1\n"^M
=cmd-param-changed,param="max-completions",value="1"^M
^done^M
(gdb) ^M
FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 1 (unexpected output)
Expecting: ^(3-complete br[^M
]+)?(.*3\^error,msg=".*[^M
]+[(]gdb[)] ^M
[ ]*)
2^done,completion="break",matches=["break"],max_completions_reached="1"^M
(gdb) ^M
set max-completions 0^M
3-complete br^M
&"set max-completions 0\n"^M
=cmd-param-changed,param="max-completions",value="0"^M
^done^M
(gdb) ^M
FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 0 (unexpected output)
...
Comment 1 Tom de Vries 2019-06-21 07:09:04 UTC
Hmm, that must have been due to high load, I can't reproduce this in a single test-case run.

Diff between passing and failing gdb.log:
...
$ diff -u 2 1 | more
--- 2   2019-06-21 09:03:43.515728516 +0200
+++ 1   2019-06-21 09:03:52.379673484 +0200
@@ -4,24 +4,22 @@
 ]+[(]gdb[)] 
 [ ]*)
 set max-completions 1
-&"set max-completions 1\n"
 2-complete br
+&"set max-completions 1\n"
 =cmd-param-changed,param="max-completions",value="1"
 ^done
 (gdb) 
-2^done,completion="break",matches=["break"],max_completions_reached="1"
-(gdb) 
-PASS: gdb.mi/mi-complete.exp: -complete br, max-completions 1
+FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 1 (unexpected output)
 Expecting: ^(3-complete br[
 ]+)?(.*3\^error,msg=".*[
 ]+[(]gdb[)] 
 [ ]*)
+2^done,completion="break",matches=["break"],max_completions_reached="1"
+(gdb) 
 set max-completions 0
+3-complete br
 &"set max-completions 0\n"
 =cmd-param-changed,param="max-completions",value="0"
 ^done
 (gdb) 
-3-complete br
-3^error,msg="max-completions is zero, completion is disabled."
-(gdb) 
-PASS: gdb.mi/mi-complete.exp: -complete br, max-completions 0
+FAIL: gdb.mi/mi-complete.exp: -complete br, max-completions 0 (unexpected output)
...
Comment 2 Jan Vrany 2019-06-21 09:00:15 UTC
How did you run it? 

I just compiled master (890f750a3b053) and run several times

   make check RUNTESTFLAGS='TRANSCRIPT=y gdb.mi/*.exp'

but got no failure.
Comment 3 Tom de Vries 2019-06-21 09:01:33 UTC
(In reply to Jan Vrany from comment #2)
> How did you run it? 

It happened during high load.
Comment 4 Tom de Vries 2019-07-19 13:36:59 UTC
I can easily reproduce this using the stress tool ( https://people.seas.harvard.edu/~apw/stress/ ) by doing:
...
$ stress -c $(($(cat /proc/cpuinfo | grep -c "^processor") + 1))
...
(so that's stress -c 5 for my cpu with 4 processors)

and running the test-case in a loop:
...
$ for n in  $(seq 1 100); do ./test.sh ; done 2>&1 | grep "expected passes"
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            8
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            8
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            8
# of expected passes            8
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            8
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            8
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            8
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            8
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            8
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            7
# of expected passes            7
# of expected passes            9
# of expected passes            7
# of expected passes            9
# of expected passes            7
...
Comment 5 Tom de Vries 2019-07-19 13:57:00 UTC
I think the problem in the test-case is that you issue two commands, without waiting for the output of the first, and then expect the various output streams resulting from the two commands to be interleaved in a certain way.

Using this patch, I wait for result of the first command before issuing the second:
...
diff --git a/gdb/testsuite/gdb.mi/mi-complete.exp b/gdb/testsuite/gdb.mi/mi-complete.exp
index 692b004fd9..5b9613548f 100644
--- a/gdb/testsuite/gdb.mi/mi-complete.exp
+++ b/gdb/testsuite/gdb.mi/mi-complete.exp
@@ -58,14 +58,16 @@ mi_gdb_test "-info-gdb-mi-command complete" \
 
 # Limit max completions and check that max_completions_reached=\"0\" is set
 # to 1.
-send_gdb "set max-completions 1\n"
+mi_gdb_test "set max-completions 1" ".*=cmd-param-changed.*\\^done" \
+    "set max-completions 1"
 
 mi_gdb_test "2-complete br" \
             ".*2\\^done,completion=\"br\[A-Za-z0-9-\]+\",matches=\\\[\"br\[A-Za-z0-9-\]+\"\\\],max_completions_re
ached=\"1\"" \
             "-complete br, max-completions 1"
 
 # Disable completions and check an error is returned
-send_gdb "set max-completions 0\n"
+mi_gdb_test "set max-completions 0" ".*=cmd-param-changed.*\\^done" \
+    "set max-completions 0"
 
 mi_gdb_test "3-complete br" \
             ".*3\\^error,msg=\".*" \
...
and manage to get a 100/100 PASS score.
Comment 7 Sourceware Commits 2019-07-23 08:39:14 UTC
The master branch has been updated by Tom de Vries <vries@sourceware.org>:

https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=5ba29434765feed692b6342a8b0f853050be2402

commit 5ba29434765feed692b6342a8b0f853050be2402
Author: Tom de Vries <tdevries@suse.de>
Date:   Tue Jul 23 10:38:33 2019 +0200

    [gdb/testsuite] Fix command result testing in mi-complete.exp
    
    When running gdb.mi/mi-complete.exp in conjunction with:
    ...
    $ stress -c $(($(cat /proc/cpuinfo | grep -c "^processor") + 1))
    ...
    we get less than 50% full passes:
    ...
    $ for n in  $(seq 1 100); do \
        make V=1 -O check \
          'RUNTESTFLAGS=gdb.mi/mi-complete.exp --target_board=unix'; \
      done 2>&1 \
      | grep "expected passes" | sort | uniq -c
         45 # of expected passes            7
          9 # of expected passes            8
         46 # of expected passes            9
    ...
    
    A diff between a passing and failing gdb.log shows this difference:
    ...
    -&"set max-completions 1\n"
     2-complete br
    +&"set max-completions 1\n"
    ...
    
    The problem is that the test-case issues the "set max-completion <n>" command,
    and without waiting for the output issues a next command, and tries to parse
    the results of both commands, expecting a specific interleaving of the various
    output streams.
    
    Fix the FAIL by waiting for the result of the "set max-completion <n>" command
    before issuing another command.
    
    Tested on x86_64-linux.
    
    gdb/testsuite/ChangeLog:
    
    2019-07-23  Tom de Vries  <tdevries@suse.de>
    
    	PR testsuite/24711
    	* gdb.mi/mi-complete.exp: Wait for "set max-completions" result before
    	issuing next command.
Comment 8 Tom de Vries 2019-07-23 08:39:47 UTC
Patch committed, marking resolved-fixed.