Bug 31440 - [gdb] FAIL: gdb.python/py-progspace-events.exp: inferior 1 (timeout)
Summary: [gdb] FAIL: gdb.python/py-progspace-events.exp: inferior 1 (timeout)
Status: NEW
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: 2024-03-02 07:14 UTC by Tom de Vries
Modified: 2024-03-04 12:21 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 2024-03-02 07:14:11 UTC
On arm-linux I ran into:
...
(gdb) PASS: gdb.python/py-progspace-events.exp: continue until inferior 2 exits
inferior 1^M
[Switching to inferior 1 [process 5199] (/home/rock/gdb/build/gdb/testsuite/outputs/gdb.python/py-progspace-events/py-progspace-events)]^M
[Switching to thread 1.1 (Thread 0xf77d0ce0 (LWP 5199))]^M
#0  breakpt () at /home/rock/gdb/src/gdb/testsuite/gdb.python/py-progspace-events.c:28^M
28      { /* Nothing.  */ }^M
(gdb) FreeProgspaceEvent: <gdb.Progspace object at 0xabaf03a0>^M
FAIL: gdb.python/py-progspace-events.exp: inferior 1 (timeout)
...

Looks like a missing no-prompt-anchor.
Comment 1 Tom de Vries 2024-03-03 11:40:16 UTC
Reproducible on x86_64:
...
$ for n in $(seq 1 100); do taskset -c 11 ./test.sh 2>&1 | grep "# of " | sort -u; done
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		11
# of unexpected failures	2
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		12
# of unexpected failures	1
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		12
# of unexpected failures	1
# of expected passes		13
# of expected passes		11
# of unexpected failures	2
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		11
# of unexpected failures	2
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		11
# of unexpected failures	2
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
# of expected passes		13
^C
...
Comment 2 Tom de Vries 2024-03-04 08:25:53 UTC
Hmm, the test-case says:
...
# Switch to inferior 2 and continue until we hit breakpt.                                                             
gdb_test "inferior 2" "\\\[Switching to inferior 2 .*"
gdb_continue_to_breakpoint "run to breakpt in inferior 2"

# Let inferior 2 exit.  The new program space is not removed at this                                                  
# point.                                                                                                              
gdb_test "continue" \
    [multi_line \
         "^Continuing\\." \
         "\\\[Inferior $decimal \[^\r\n\]+ exited normally\\\]"] \
    "continue until inferior 2 exits"

gdb_test "inferior 1" "\\\[Switching to inferior 1 .*"

# Step the inferior.  During this process GDB will prune the now                                                      
# defunct inferior, which deletes its program space, which should                                                     
# trigger the FreeProgspaceEvent.                                                                                     
...

So, it explicitly states that the FreeProgspaceEvent should not happen until after the step is issued.

At this point I'm not sure if this is indeed a test-case issue.
Comment 3 Tom de Vries 2024-03-04 08:58:44 UTC
I build gdb at commit 59912fb2d22 ("gdb: add Python events for program space addition and removal"), which introduced the test-case.

Already there I see the same FAIL, and also this variant which looks slightly different:
...
(gdb) PASS: gdb.python/py-progspace-events.exp: continue until inferior 2 exits
inferior 1^M
[Switching to inferior 1 [process 24038] (/data/vries/gdb/leap-15-4/build/gdb/testsuite/outputs/gdb.python/py-progspace-events/py-progspace-events)]^M
[Switching to thread 1.1 (process 24038)]^M
#0  breakpt () at /data/vries/gdb/src/gdb/testsuite/gdb.python/py-progspace-events.c:28^M
28      { /* Nothing.  */ }^M
(gdb) PASS: gdb.python/py-progspace-events.exp: inferior 1
FreeProgspaceEvent: <gdb.Progspace object at 0x7efcaa520300>^M
step^M
do_parent_stuff () at /data/vries/gdb/src/gdb/testsuite/gdb.python/py-progspace-events.c:41^M
41        ++global_var;^M
(gdb) FAIL: gdb.python/py-progspace-events.exp: step
...

The test-case seems to fail about 1 out of 4 times.
Comment 4 Tom de Vries 2024-03-04 09:31:40 UTC
I wondered about using print in the python script, and tried this patch, but that doesn't fix it either:
...
diff --git a/gdb/testsuite/gdb.python/py-progspace-events.py b/gdb/testsuite/gdb.python/py-progspace-events.py
index 23c6fc52f4d..6f41888b65b 100644
--- a/gdb/testsuite/gdb.python/py-progspace-events.py
+++ b/gdb/testsuite/gdb.python/py-progspace-events.py
@@ -21,11 +21,13 @@ import gdb.events
 
 
 def new_progspace(event):
-    print("NewProgspaceEvent: %s" % str(event.progspace))
+    gdb.write("NewProgspaceEvent: %s\n" % str(event.progspace))
+    gdb.flush()
 
 
 def free_progspace(event):
-    print("FreeProgspaceEvent: %s" % str(event.progspace))
+    gdb.write("FreeProgspaceEvent: %s\n" % str(event.progspace))
+    gdb.flush()
 
 
 gdb.events.new_progspace.connect(new_progspace)
...
Comment 5 Tom de Vries 2024-03-04 10:54:51 UTC
I added some debug printfs, and got the following output.

Passing case:
...
(gdb) PASS: gdb.python/py-progspace-events.exp: continue to breakpoint: run to breakpt in inferior 2
continue^M
Continuing.^M
not removable: inf 1^M
not deletable: inf 2^M
[Inferior 2 (process 4549) exited normally]^M
not removable: inf 1^M
not deletable: inf 2^M
(gdb) not removable: inf 1^M
not deletable: inf 2^M
PASS: gdb.python/py-progspace-events.exp: continue until inferior 2 exits
inferior 1^M
[Switching to inferior 1 [process 4546] (py-progspace-events)]^M
[Switching to thread 1.1 (process 4546)]^M
#0  breakpt () at py-progspace-events.c:28^M
28      { /* Nothing.  */ }^M
(gdb) PASS: gdb.python/py-progspace-events.exp: inferior 1
step^M
not deletable: inf 1^M
delete_inferior: inf 2^M
FreeProgspaceEvent: <gdb.Progspace object at 0x7efd1faf0ee0>^M
...

Failing case:
...
(gdb) PASS: gdb.python/py-progspace-events.exp: continue to breakpoint: run to breakpt in inferior 2
continue^M
Continuing.^M
not removable: inf 1^M
not deletable: inf 2^M
[Inferior 2 (process 4752) exited normally]^M
not removable: inf 1^M
not deletable: inf 2^M
(gdb) PASS: gdb.python/py-progspace-events.exp: continue until inferior 2 exits
inferior 1^M
[Switching to inferior 1 [process 4742] (py-progspace-events)]^M
[Switching to thread 1.1 (process 4742)]^M
#0  breakpt () at py-progspace-events.c:28^M
28      { /* Nothing.  */ }^M
(gdb) not deletable: inf 1^M
delete_inferior: inf 2^M
FreeProgspaceEvent: <gdb.Progspace object at 0x7f3a6faf0ee0>^M
FAIL: gdb.python/py-progspace-events.exp: inferior 1 (timeout)
step^M
...

So, it seems there's a race between some event and the "inferior 1" command.

In the passing case, the event is handled first.  During handling, prune_inferiors is called, but it can't remove inferior 1, because it's still the current one.

In the failing case, the "inferior 1" is handled first. Then during handling of the event, prune_inferiors is called, and it can remove inferior 1 because it's no longer the current one.
Comment 6 Tom de Vries 2024-03-04 10:58:32 UTC
By pruning the inferiors asap:
...
diff --git a/gdb/inferior.c b/gdb/inferior.c
index 5ff5eb98955..9dc34ed72e4 100644
--- a/gdb/inferior.c
+++ b/gdb/inferior.c
@@ -791,6 +791,7 @@ inferior_command (const char *args, int from_tty)
 	  notify_user_selected_context_changed
 	    (USER_SELECTED_INFERIOR);
 	}
+      prune_inferiors ();
     }
 }
 
...
we get stable output:
...
(gdb) PASS: gdb.python/py-progspace-events.exp: continue until inferior 2 exits
inferior 1^M
[Switching to inferior 1 [process 5991] (py-progspace-events)]^M
[Switching to thread 1.1 (process 5991)]^M
#0  breakpt () at py-progspace-events.c:28^M
28      { /* Nothing.  */ }^M
FreeProgspaceEvent: <gdb.Progspace object at 0x7f62ca9b0ee0>^M
(gdb) PASS: gdb.python/py-progspace-events.exp: inferior 1
...