watch_thread_num.exp and targets with fairer event reporting
authorPedro Alves <palves@redhat.com>
Mon, 29 Dec 2014 19:41:05 +0000 (19:41 +0000)
committerPedro Alves <palves@redhat.com>
Fri, 9 Jan 2015 14:39:41 +0000 (14:39 +0000)
This patch fixes the watch_thread_num.exp test to work when the target
is better at making event handling be fair among threads.

I wrote patches that make GDB native and GDBserver event handling
fairer between threads.  That is, if threads A and B both
simultaneously trigger some debug event, GDB will pick either A or B
at random, rather than always handling the event of A first.  There's
code for that in the Linux backends (gdb and gdbserver) already, but
it can be improved, and only works in all-stop mode.

With those fixes in place, I found that the watch_thread_num.exp would
often time out.  The problem is that the test only works _because_
event handling isn't as fair as intended.  With the fairness fixes,
the test falls victim of PR10116 (gdb drops watchpoints on
multi-threaded apps) quite often.

To expand on the PR10116 reference, consider that stop events are
serialized to GDB core, through target_wait.  Say a thread-specific
watchpoint as set on thread A.  When the "right" thread and some other
"wrong" thread both trigger a watchpoint simultaneously, the target
may report the "wrong" thread's hit to GDB first (thread B).  When
handling that event, GDB notices the watchpoint is for another thread,
and so shouldn't cause a user-visible stop.  On resume, GDB saves the
now current value of the watched expression.  Afterwards, the "right"
thread (thread A) reports its watchpoint trigger.  But the watched
value hasn't changed since GDB last saved it, and so GDB doesn't
report the watchpoint hit to the user.

The way the test is written, the watchpoint is associated with the
first thread that happens to report an event.  It happens that GDB is
processing events much more often for one of the threads, which
usually will be that same first thread.

Hacking the test with "set debug infrun 1", we see exactly that:

$ grep  "infrun.*\[Thread.*," testsuite/gdb.log | sort | uniq -c | sort -nr
     70 infrun:   8798 [Thread 8798],
     37 infrun:   8798 [Thread 8802],
     36 infrun:   8798 [Thread 8804],
     36 infrun:   8798 [Thread 8803],
     35 infrun:   8798 [Thread 8805],
     34 infrun:   8798 [Thread 8806],

The first column shows the number of times the target reported an
event for that thread, from:

 infrun: target_wait (-1, status) =
 infrun:   8798 [Thread 8798],
 infrun:   status->kind = stopped, signal = GDB_SIGNAL_TRAP

This masks out the PR10116 issue.

However, if the target is better at giving equal priority to all
threads, the PR10116 issue happens often, so it may take quite a while
for the right thread to be the first to report its watchpoint event
just after the memory being watched really changed, resulting in test
time outs.

Here's the number of events handled for each thread on a gdbserver run
with the event fairness patches:

$ grep  "infrun.*\[Thread.*," gdb.log | sort | uniq -c
   2961 infrun:   13591 [Thread 13591],
   2956 infrun:   13591 [Thread 13595],
   2941 infrun:   13591 [Thread 13596],
   2932 infrun:   13591 [Thread 13597],
   2905 infrun:   13591 [Thread 13598],
   2891 infrun:   13591 [Thread 13599],

Note how the number of events is much higher.  The test routinely
takes over 10 seconds to finish on my machine rather than under a
second as with unpatched gdbserver, when it succeeds, but often it'll
fail with timeouts too.

So to make the test robust, this patch switches the tests to using
"awatch" instead of "watch", as access watchpoints don't care about
the watchpoint's "old value".  With this, the test always finishes
quickly, and we can even bump the number of threads concurrently
writting to the shared variable, to have better assurance we're really
testing the case of the "wrong" thread triggering a watchpoint.

Here's the number of events I see for each thread on a run on my
machine, with a gdbserver patched with the event fairness series:

$ grep  "infrun.*\[Thread.*," testsuite/gdb.log | sort | uniq -c
      5 infrun:   5298 [Thread 5302],
      4 infrun:   5298 [Thread 5303],
      4 infrun:   5298 [Thread 5304],
      4 infrun:   5298 [Thread 5305],
      4 infrun:   5298 [Thread 5306],
      4 infrun:   5298 [Thread 5307],
      4 infrun:   5298 [Thread 5308],
      4 infrun:   5298 [Thread 5309],
      4 infrun:   5298 [Thread 5310],
      4 infrun:   5298 [Thread 5311],
      4 infrun:   5298 [Thread 5312],
      4 infrun:   5298 [Thread 5313],
      4 infrun:   5298 [Thread 5314],
      4 infrun:   5298 [Thread 5315],
      4 infrun:   5298 [Thread 5316],

gdb/testsuite/
2015-01-09  Pedro Alves  <palves@redhat.com>

* gdb.base/annota1.exp (thread_test): Use srcfile and binfile from
the global scope.  Set a breakpoint after all threads are started
rather than stepping over two source lines.  Expect the prompt.
* gdb.base/watch_thread_num.c (threads_started_barrier): New
global.
(NUM): Now 15.
(main): Use threads_started_barrier to wait for all threads to
start.  Main thread no longer calls thread_function.  Exit after
180 seconds.
(loop): New function.
(thread_function): Wait on threads_started_barrier barrier.  Call
'loop' at each iteration.
* gdb.base/watch_thread_num.exp: Continue to breakpoint after all
threads have started, instead of hardcoding number of "next"
steps.  Use an access watchpoint instead of a write watchpoint.

gdb/testsuite/ChangeLog
gdb/testsuite/gdb.base/annota1.exp
gdb/testsuite/gdb.base/watch_thread_num.c
gdb/testsuite/gdb.base/watch_thread_num.exp

index cd38459b698d82c3946cedcb6c4854ab298d4957..aa1e22b8d3e01e1690ab69493dc2f4e15570a564 100644 (file)
@@ -1,3 +1,21 @@
+2015-01-09  Pedro Alves  <palves@redhat.com>
+
+       * gdb.base/annota1.exp (thread_test): Use srcfile and binfile from
+       the global scope.  Set a breakpoint after all threads are started
+       rather than stepping over two source lines.  Expect the prompt.
+       * gdb.base/watch_thread_num.c (threads_started_barrier): New
+       global.
+       (NUM): Now 15.
+       (main): Use threads_started_barrier to wait for all threads to
+       start.  Main thread no longer calls thread_function.  Exit after
+       180 seconds.
+       (loop): New function.
+       (thread_function): Wait on threads_started_barrier barrier.  Call
+       'loop' at each iteration.
+       * gdb.base/watch_thread_num.exp: Continue to breakpoint after all
+       threads have started, instead of hardcoding number of "next"
+       steps.  Use an access watchpoint instead of a write watchpoint.
+
 2015-01-09  Pedro Alves  <palves@redhat.com>
 
        * gdb.threads/ia64-sigill.c (threads_started_barrier): New global.
index 239b047b17a36cef1efc00daf914b67d321edafd..c19b9456a259644b793e3136714a69b6783c5896 100644 (file)
@@ -440,7 +440,7 @@ if { [remote_file host exists core] } {
 }
 
 proc thread_test {} {
-    global subdir srcdir testfile
+    global subdir srcdir testfile srcfile binfile
     global gdb_prompt old_gdb_prompt
     set srcfile watch_thread_num.c
     set binfile [standard_output_file ${testfile}-watch_thread_num]
@@ -457,6 +457,9 @@ proc thread_test {} {
            return
        }
 
+       set linenum [gdb_get_line_number "all threads started"]
+       gdb_breakpoint "$linenum"
+
        set gdb_prompt \
            "\r\n\032\032pre-prompt\r\n$gdb_prompt \r\n\032\032prompt\r\n"
 
@@ -465,8 +468,8 @@ proc thread_test {} {
            }
        }
 
-       gdb_test_multiple "next 2" "new thread" {
-           -re ".*\032\032new-thread" {
+       gdb_test_multiple "continue" "new thread" {
+           -re "\032\032new-thread.*\r\n$gdb_prompt$" {
                pass "new thread"
            }
        }
index 1466aedba4071c112d85c9d1db8552b20495c251..55b4867bd1728d2a2211fcdeaaedf5fdcd05fcbc 100644 (file)
 
 void *thread_function (void *arg); /* Pointer to function executed by each thread */
 
-#define NUM 5
+static pthread_barrier_t threads_started_barrier;
+
+#define NUM 15
+
+static int num_threads = NUM;
 
 static unsigned int shared_var = 1;
 
@@ -37,6 +41,8 @@ int main () {
     void *thread_result;
     long i;
 
+    pthread_barrier_init (&threads_started_barrier, NULL, NUM + 1);
+
     for (i = 0; i < NUM; i++)
       {
         res = pthread_create (&threads[i],
@@ -45,18 +51,29 @@ int main () {
                             (void *) i);
       }
 
-    thread_result = thread_function ((void *) i);
+    pthread_barrier_wait (&threads_started_barrier);
+
+    sleep (180); /* all threads started */
 
     exit (EXIT_SUCCESS);
 }
 
+void
+loop (void)
+{
+}
+
 void *thread_function (void *arg) {
     int my_number = (long) arg;
+
+    pthread_barrier_wait (&threads_started_barrier);
+
     /* Don't run forever.  Run just short of it :)  */
     while (shared_var > 0)
       {
         shared_var++;
        usleep (1); /* Loop increment.  */
+       loop ();
       }
 
     pthread_exit (NULL);
index 571005d7d6d4cd8a608b43cee9ce41543b855bf6..d559f22386fb561570785fbb027bf23199571e1d 100644 (file)
@@ -47,12 +47,14 @@ if { ![runto main] } then {
 gdb_test "watch shared_var thread 0" "Unknown thread 0\." "Watchpoint on invalid thread"
 gdb_test "watch shared_var thread" "A syntax error in expression, near `thread'\." "Invalid watch syntax"
 
-gdb_test "Next 5" ".*"
+set bpexitline [gdb_get_line_number "all threads started"]
+gdb_breakpoint "$bpexitline"
+gdb_continue_to_breakpoint "all threads started"
 
-gdb_test "break thread_function" "Breakpoint \[0-9\].*" \
-  "Set breakpoint at thread_function"
+gdb_test "break loop" "Breakpoint \[0-9\].*" \
+  "Set breakpoint at loop"
 
-gdb_test "continue" ".*Breakpoint 2.*" "Stopped in thread_function"
+gdb_test "continue" ".*Breakpoint .*loop.*" "Stopped in loop"
 
 gdb_test_multiple "thread" "Thread command" {
     -re ".*Current thread is (\[0-9\]*).*$gdb_prompt $" {
@@ -62,15 +64,35 @@ gdb_test_multiple "thread" "Thread command" {
 
 set thread_num "$expect_out(1,string)"
 
-gdb_test_no_output "disable 2" "Disable breakpoint 2"
-gdb_test "watch shared_var thread $thread_num" "Hardware watchpoint 3: shared_var" "Watchpoint on shared variable"
-gdb_test "info breakpoint 3" "stop only in thread $thread_num"
+delete_breakpoints
 
-for {set i 1} {$i <= 10} {incr i 1} {
+# We use an access watchpoint rather than a write watchpoint, because
+# GDB can drop the latter when multiple threads trigger events
+# simultaneously, on targets with continuable watchpoints, such as
+# x86.  See PR breakpoints/10116.
+
+gdb_test "awatch shared_var thread $thread_num" \
+    "Hardware access \\(read/write\\) watchpoint .*: shared_var.*" \
+    "Watchpoint on shared variable"
+
+gdb_test "info breakpoint \$bpnum" \
+    "stop only in thread $thread_num" \
+    "info breakpoint shows watchpoint is thread-specific"
+
+for {set i 1} {$i <= 5} {incr i} {
     set watchpoint "Watchpoint triggered iteration $i"
     set check "Check thread that triggered iteration $i"
 
-    gdb_test "continue" "Hardware watchpoint 3: shared_var.*" $watchpoint
+    set test $watchpoint
+    gdb_test_multiple "continue" $test {
+       -re "infrun:" {
+           # Avoid timeouts when debugging GDB.
+           exp_continue
+       }
+       -re "Hardware access \\(read/write\\) watchpoint .*: shared_var.*$gdb_prompt $" {
+           pass $test
+       }
+    }
     gdb_test "thread" ".*Current thread is $thread_num .*" $check
 }