DRD now prints where a mutex appeared for the first time in addition to
the mutex address when an error message is printed for condition
variables.


git-svn-id: svn://svn.valgrind.org/valgrind/trunk@8296 a5019735-40e9-0310-863c-91ae7b9d1cf9
diff --git a/exp-drd/drd_clientobj.h b/exp-drd/drd_clientobj.h
index 0068dc3..b8297b7 100644
--- a/exp-drd/drd_clientobj.h
+++ b/exp-drd/drd_clientobj.h
@@ -66,6 +66,7 @@
   DrdThreadId owner;           // owner if locked, last owner if free.
   Segment*    last_locked_segment;
   ULong       acquiry_time_ms;
+  ExeContext* first_observed_at;
   ExeContext* acquired_at;
 };
 
diff --git a/exp-drd/drd_error.c b/exp-drd/drd_error.c
index e4f3581..842a637 100644
--- a/exp-drd/drd_error.c
+++ b/exp-drd/drd_error.c
@@ -23,21 +23,22 @@
 */
 
 
+#include "drd_clientobj.h"        /* struct mutex_info        */
 #include "drd_error.h"
 #include "drd_malloc_wrappers.h"
-#include "drd_mutex.h"            // struct mutex_info
-#include "drd_suppression.h"      // drd_start_suppression()
-#include "pub_drd_bitmap.h"       // LHS_W, ...
+#include "drd_mutex.h"
+#include "drd_suppression.h"      /* drd_start_suppression()  */
+#include "pub_drd_bitmap.h"       /* LHS_W, ...               */
 #include "pub_tool_vki.h"
 #include "pub_tool_basics.h"
-#include "pub_tool_libcassert.h"  // tl_assert()
-#include "pub_tool_libcbase.h"    // strlen()
-#include "pub_tool_libcfile.h"    // VG_(get_startup_wd)()
-#include "pub_tool_libcprint.h"   // VG_(printf)()
+#include "pub_tool_libcassert.h"  /* tl_assert()              */
+#include "pub_tool_libcbase.h"    /* strlen()                 */
+#include "pub_tool_libcfile.h"    /* VG_(get_startup_wd)()    */
+#include "pub_tool_libcprint.h"   /* VG_(printf)()            */
 #include "pub_tool_machine.h"
-#include "pub_tool_mallocfree.h"  // VG_(malloc), VG_(free)
-#include "pub_tool_threadstate.h" // VG_(get_pthread_id)()
-#include "pub_tool_tooliface.h"   // VG_(needs_tool_errors)()
+#include "pub_tool_mallocfree.h"  /* VG_(malloc), VG_(free)   */
+#include "pub_tool_threadstate.h" /* VG_(get_pthread_id)()    */
+#include "pub_tool_tooliface.h"   /* VG_(needs_tool_errors)() */
 
 
 /* Local variables. */
@@ -50,8 +51,9 @@
   s_drd_show_conflicting_segments = scs;
 }
 
-/* Describe a data address range [a,a+len[ as good as possible, for error */
-/* messages, putting the result in ai. */
+/** Describe a data address range [a,a+len[ as good as possible, for error
+ *  messages, putting the result in ai.
+ */
 static
 void describe_malloced_addr(Addr const a, SizeT const len, AddrInfo* const ai)
 {
@@ -68,6 +70,24 @@
   }
 }
 
+/** Report where a mutex has been observed for the first time. The printed
+ *  call stack will either refer to a pthread_mutex_init() or a
+ *  pthread_mutex_lock() call.
+ */
+static void mutex_first_observed(const Addr mutex)
+{
+  struct mutex_info* mi;
+
+  mi = mutex_get(mutex);
+  if (mi)
+  {
+    tl_assert(mi->first_observed_at);
+    VG_(message)(Vg_UserMsg,
+                 "Mutex 0x%lx was first observed at:", mutex);
+    VG_(pp_ExeContext)(mi->first_observed_at);
+  }
+}
+
 static
 void drd_report_data_race2(Error* const err, const DataRaceErrInfo* const dri)
 {
@@ -171,10 +191,11 @@
     CondRaceErrInfo* cei = (CondRaceErrInfo*)(VG_(get_error_extra)(e));
     VG_(message)(Vg_UserMsg,
                  "Probably a race condition: condition variable 0x%lx has been"
-                 " signalled but the associated mutex 0x%lx is not locked"
-                 " by the signalling thread",
+                 " signaled but the associated mutex 0x%lx is not locked"
+                 " by the signalling thread.",
                  cei->cond, cei->mutex);
     VG_(pp_ExeContext)(VG_(get_error_where)(e));
+    mutex_first_observed(cei->mutex);
     break;
   }
   case CondDestrErr: {
@@ -185,10 +206,11 @@
                  cdi->cond, cdi->mutex,
                  DrdThreadIdToVgThreadId(cdi->tid), cdi->tid);
     VG_(pp_ExeContext)(VG_(get_error_where)(e));
+    mutex_first_observed(cdi->mutex);
     break;
   }
   case SemaphoreErr: {
-    SemaphoreErrInfo* sei =(SemaphoreErrInfo*)(VG_(get_error_extra)(e));
+    SemaphoreErrInfo* sei = (SemaphoreErrInfo*)(VG_(get_error_extra)(e));
     tl_assert(sei);
     VG_(message)(Vg_UserMsg,
                  "%s: semaphore 0x%lx",
diff --git a/exp-drd/drd_mutex.c b/exp-drd/drd_mutex.c
index dd009de..823da1c 100644
--- a/exp-drd/drd_mutex.c
+++ b/exp-drd/drd_mutex.c
@@ -77,6 +77,7 @@
   p->owner               = DRD_INVALID_THREADID;
   p->last_locked_segment = 0;
   p->acquiry_time_ms     = 0;
+  p->first_observed_at   = VG_(record_ExeContext)(VG_(get_running_tid)(), 0);
   p->acquired_at         = 0;
 }
 
@@ -109,6 +110,7 @@
   p->last_locked_segment = 0;
 }
 
+/** Let Valgrind report that there is no mutex object at address 'mutex'. */
 static void not_a_mutex(const Addr mutex)
 {
   MutexErrInfo MEI = { mutex, -1, DRD_INVALID_THREADID };
diff --git a/exp-drd/drd_mutex.h b/exp-drd/drd_mutex.h
index 3babae4..e241f67 100644
--- a/exp-drd/drd_mutex.h
+++ b/exp-drd/drd_mutex.h
@@ -23,9 +23,6 @@
 */
 
 
-// Mutex state information: owner thread and recursion count.
-
-
 #ifndef __DRD_MUTEX_H
 #define __DRD_MUTEX_H
 
diff --git a/exp-drd/tests/pth_cond_race.stderr.exp b/exp-drd/tests/pth_cond_race.stderr.exp
index 6cea56a..8e38ee6 100644
--- a/exp-drd/tests/pth_cond_race.stderr.exp
+++ b/exp-drd/tests/pth_cond_race.stderr.exp
@@ -1,10 +1,13 @@
 
 Thread 2:
-Probably a race condition: condition variable 0x........ has been signalled but the associated mutex 0x........ is not locked by the signalling thread
+Probably a race condition: condition variable 0x........ has been signaled but the associated mutex 0x........ is not locked by the signalling thread.
    at 0x........: pthread_cond_signal* (drd_pthread_intercepts.c:?)
    by 0x........: thread_func (pth_cond_race.c:?)
    by 0x........: vg_thread_wrapper (drd_pthread_intercepts.c:?)
    by 0x........: (within libpthread-?.?.so)
    by 0x........: clone (in /...libc...)
+Mutex 0x........ was first observed at:
+   at 0x........: pthread_mutex_init (drd_pthread_intercepts.c:?)
+   by 0x........: main (pth_cond_race.c:?)
 
 ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)
diff --git a/exp-drd/tests/tc23_bogus_condwait.stderr.exp b/exp-drd/tests/tc23_bogus_condwait.stderr.exp
index b64e170..7ce65f2 100644
--- a/exp-drd/tests/tc23_bogus_condwait.stderr.exp
+++ b/exp-drd/tests/tc23_bogus_condwait.stderr.exp
@@ -4,7 +4,7 @@
    by 0x........: main (tc23_bogus_condwait.c:69)
 
 Thread 3:
-Probably a race condition: condition variable 0x........ has been signalled but the associated mutex 0x........ is not locked by the signalling thread
+Probably a race condition: condition variable 0x........ has been signaled but the associated mutex 0x........ is not locked by the signalling thread.
    at 0x........: pthread_cond_signal* (drd_pthread_intercepts.c:?)
    by 0x........: rescue_me (tc23_bogus_condwait.c:20)
    by 0x........: vg_thread_wrapper (drd_pthread_intercepts.c:?)
@@ -17,12 +17,15 @@
    by 0x........: main (tc23_bogus_condwait.c:72)
 
 Thread 3:
-Probably a race condition: condition variable 0x........ has been signalled but the associated mutex 0x........ is not locked by the signalling thread
+Probably a race condition: condition variable 0x........ has been signaled but the associated mutex 0x........ is not locked by the signalling thread.
    at 0x........: pthread_cond_signal* (drd_pthread_intercepts.c:?)
    by 0x........: rescue_me (tc23_bogus_condwait.c:24)
    by 0x........: vg_thread_wrapper (drd_pthread_intercepts.c:?)
    by 0x........: (within libpthread-?.?.so)
    by 0x........: clone (in /...libc...)
+Mutex 0x........ was first observed at:
+   at 0x........: pthread_mutex_init (drd_pthread_intercepts.c:?)
+   by 0x........: main (tc23_bogus_condwait.c:51)
 
 Thread 1:
 The object at address 0x........ is not a mutex.
@@ -30,7 +33,7 @@
    by 0x........: main (tc23_bogus_condwait.c:75)
 
 Thread 3:
-Probably a race condition: condition variable 0x........ has been signalled but the associated mutex 0x........ is not locked by the signalling thread
+Probably a race condition: condition variable 0x........ has been signaled but the associated mutex 0x........ is not locked by the signalling thread.
    at 0x........: pthread_cond_signal* (drd_pthread_intercepts.c:?)
    by 0x........: rescue_me (tc23_bogus_condwait.c:28)
    by 0x........: vg_thread_wrapper (drd_pthread_intercepts.c:?)
@@ -43,12 +46,15 @@
    by 0x........: main (tc23_bogus_condwait.c:78)
 
 Thread 3:
-Probably a race condition: condition variable 0x........ has been signalled but the associated mutex 0x........ is not locked by the signalling thread
+Probably a race condition: condition variable 0x........ has been signaled but the associated mutex 0x........ is not locked by the signalling thread.
    at 0x........: pthread_cond_signal* (drd_pthread_intercepts.c:?)
    by 0x........: rescue_me (tc23_bogus_condwait.c:32)
    by 0x........: vg_thread_wrapper (drd_pthread_intercepts.c:?)
    by 0x........: (within libpthread-?.?.so)
    by 0x........: clone (in /...libc...)
+Mutex 0x........ was first observed at:
+   at 0x........: pthread_mutex_init (drd_pthread_intercepts.c:?)
+   by 0x........: main (tc23_bogus_condwait.c:53)
 The impossible happened: mutex 0x........ is locked simultaneously by two threads (recursion count 1, owners 2 and 1) !
 
 Thread 2: