With my latest run with tastset -c 0, I have: ... FAIL: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for first command output, command length 234 ... In more detail: ... PASS: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for second command output, command length 233 length of first command is 234 -data-evaluate-expression $a^M -data-evaluate-expression $^doneb^M ,value="\"FIRST COMMAND\""^M (gdb) ^M ^done,value="\"TEST COMPLETE\""^M (gdb) ^M FAIL: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for first command output, command length 234 PASS: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for second command output, command length 234 ... Looks like the '^done' ended up intermixed with '-data-evaluate-expression $b^M'. Doesn't reproduce every time, but manage to reproduce a couple of times: ... FAIL: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for first command output, command length 487 ... and: ... FAIL: gdb.mi/mi-multi-commands.exp: args=separate-mi-tty: look for first command output, command length 745 ... The latter has intermixing at a different location: ... ^done-data-evaluate-expression $b^M ,value="\"FIRST COMMAND\""^M ...
Also ran into this with check-read1.
Hi Tom, Thanks for reporting this. I took another look at the MI code, and I suspect this patch might be the way to go: ## START ## diff --git a/gdb/testsuite/gdb.mi/mi-multi-commands.exp b/gdb/testsuite/gdb.mi/mi-multi-commands.exp index d00e0aaea8b..58187b15815 100644 --- a/gdb/testsuite/gdb.mi/mi-multi-commands.exp +++ b/gdb/testsuite/gdb.mi/mi-multi-commands.exp @@ -100,7 +100,7 @@ proc run_test { args } { set seen_second_message false gdb_test_multiple "" "look for first command output, command length $i" -prompt "$mi_gdb_prompt" { - -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"" { + -re "\\^done.*,value=\"\\\\\"FIRST COMMAND\\\\\"\"" { set seen_first_message true exp_continue } ## END ## The problem is that the '^done' and the ',value="...."' are printed by two separate write calls, and so, depending on timing, it is possible that the terminal might choose to echo some output between these two write calls. I don't think the same protection is needed for the "TEST COMPLETE" case (just below the hunk I patched above) as that message is from the second (and last command), thus by the time we are printing that we know there should be no additional incoming command text that might interrupt the command output. I tried a few times to reproduce the failure you are seeing (before patching) and was not successful. If you can reproduce the failure more consistently, could you give this patch a go please and let me know if it fixes things. Thanks.
(In reply to Andrew Burgess from comment #2) > Hi Tom, > > Thanks for reporting this. I took another look at the MI code, and I > suspect this patch might be the way to go: > > ## START ## > > diff --git a/gdb/testsuite/gdb.mi/mi-multi-commands.exp > b/gdb/testsuite/gdb.mi/mi-multi-commands.exp > index d00e0aaea8b..58187b15815 100644 > --- a/gdb/testsuite/gdb.mi/mi-multi-commands.exp > +++ b/gdb/testsuite/gdb.mi/mi-multi-commands.exp > @@ -100,7 +100,7 @@ proc run_test { args } { > set seen_second_message false > > gdb_test_multiple "" "look for first command output, command length $i" > -prompt "$mi_gdb_prompt" { > - -re "\\^done,value=\"\\\\\"FIRST COMMAND\\\\\"\"" { > + -re "\\^done.*,value=\"\\\\\"FIRST COMMAND\\\\\"\"" { > set seen_first_message true > exp_continue > } > > ## END ## > > The problem is that the '^done' and the ',value="...."' are printed by two > separate write calls, and so, depending on timing, it is possible that the > terminal might choose to echo some output between these two write calls. > I see, that makes sense. > I don't think the same protection is needed for the "TEST COMPLETE" case > (just below the hunk I patched above) as that message is from the second > (and last command), thus by the time we are printing that we know there > should be no additional incoming command text that might interrupt the > command output. > Ack, sounds reasonable. > I tried a few times to reproduce the failure you are seeing (before > patching) and was not successful. If you can reproduce the failure more > consistently, could you give this patch a go please and let me know if it > fixes things. For me it's not trivial to reproduce at this point, but I managed twice in an (undisturbed, meaning afk) run of 100, like this: ... $ for n in $(seq 1 100); do echo -n "$n: "; taskset -c 0 ./test.sh 2>&1 | grep "expected passes"; cp gdb.log gdb.$n.log; done ... Then, with your patch applied, I got clean results for all 100 runs. So, LGTM.
The master branch has been updated by Andrew Burgess <aburgess@sourceware.org>: https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=77399b529808626f764bcc347be0d6e8b6b167ce commit 77399b529808626f764bcc347be0d6e8b6b167ce Author: Andrew Burgess <aburgess@redhat.com> Date: Mon May 9 16:49:03 2022 +0100 gdb/testsuite: fix occasional failure in gdb.mi/mi-multi-commands.exp In bug PR gdb/29036, another failure was reported for the test gdb.mi/mi-multi-commands.exp. This test sends two commands to GDB as a single write, and then checks that both commands are executed. The problem that was encountered here is that the output of the first command, which looks like this: ^done,value="\"FIRST COMMAND\"" Is actually produced in parts, first the '^done' is printed, then the ',value="\"FIRST COMMAND\"" is printed. What was happening is that some characters from the second command were being echoed after the '^done' had been printed, but before the value part had been printed. To avoid this issue I've relaxed the pattern that checks for the first command a little. With this fix in place the occasional failure in this test is no longer showing up. Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=29036
Fixed by commit mentioned in previous comment.