]> git.ipfire.org Git - thirdparty/valgrind.git/commitdiff
Added support for detecting locks that have been held too long.
authorBart Van Assche <bvanassche@acm.org>
Wed, 14 May 2008 12:25:00 +0000 (12:25 +0000)
committerBart Van Assche <bvanassche@acm.org>
Wed, 14 May 2008 12:25:00 +0000 (12:25 +0000)
git-svn-id: svn://svn.valgrind.org/valgrind/trunk@8079

exp-drd/drd_clientobj.h
exp-drd/drd_error.c
exp-drd/drd_error.h
exp-drd/drd_main.c
exp-drd/drd_mutex.c
exp-drd/drd_mutex.h
exp-drd/drd_rwlock.c
exp-drd/drd_rwlock.h

index abc92f5e6632b1b3dc9afdb27dd88ecf977138a0..0068dc33d7d1fa6f06d63c05ce2181e964cb3609 100644 (file)
 #define __DRD_CLIENTOBJ_H
 
 
-#include "drd_clientreq.h"   /* MutexT */
-#include "drd_thread.h"      /* DrdThreadId */
+#include "drd_clientreq.h"       /* MutexT */
+#include "drd_thread.h"          /* DrdThreadId */
 #include "pub_tool_basics.h"
+#include "pub_tool_execontext.h" /* ExeContext */
 #include "pub_tool_oset.h"
 
 
@@ -64,6 +65,8 @@ struct mutex_info
   int         recursion_count; // 0 if free, >= 1 if locked.
   DrdThreadId owner;           // owner if locked, last owner if free.
   Segment*    last_locked_segment;
+  ULong       acquiry_time_ms;
+  ExeContext* acquired_at;
 };
 
 struct cond_info
@@ -89,9 +92,9 @@ struct semaphore_info
 
 struct barrier_info
 {
-  Addr    a1;
-  ObjType type;
-  void    (*cleanup)(union drd_clientobj*);
+  Addr     a1;
+  ObjType  type;
+  void     (*cleanup)(union drd_clientobj*);
   BarrierT barrier_type;      // pthread_barrier or gomp_barrier.
   Word     count;             // Participant count in a barrier wait.
   Word     pre_iteration;     // pthread_barrier_wait() call count modulo two.
@@ -103,10 +106,12 @@ struct barrier_info
 
 struct rwlock_info
 {
-  Addr    a1;
-  ObjType type;
-  void    (*cleanup)(union drd_clientobj*);
-  OSet*   thread_info;
+  Addr        a1;
+  ObjType     type;
+  void        (*cleanup)(union drd_clientobj*);
+  OSet*       thread_info;
+  ULong       acquiry_time_ms;
+  ExeContext* acquired_at;
 };
 
 typedef union drd_clientobj
index 5e92917be07632c281a1168644278f9fc226dec3..bb198a168b9dbb1c0957f34bc101c0f684e0e839 100644 (file)
@@ -217,6 +217,21 @@ static void drd_tool_error_pp(Error* const e)
     VG_(pp_ExeContext)(VG_(get_error_where)(e));
     break;
   }
+  case HoldtimeErr: {
+    HoldtimeErrInfo* p =(HoldtimeErrInfo*)(VG_(get_error_extra)(e));
+    tl_assert(p);
+    tl_assert(p->acquired_at);
+    VG_(message)(Vg_UserMsg, "Acquired at:");
+    VG_(pp_ExeContext)(p->acquired_at);
+    VG_(message)(Vg_UserMsg,
+                 "Lock on %s 0x%lx was held during %d ms (threshold: %d ms).",
+                 VG_(get_error_string)(e),
+                 p->synchronization_object,
+                 p->hold_time_ms,
+                 p->threshold_ms);
+    VG_(pp_ExeContext)(VG_(get_error_where)(e));
+    break;
+  }
   case GenericErr: {
     //GenericErrInfo* gei =(GenericErrInfo*)(VG_(get_error_extra)(e));
     VG_(message)(Vg_UserMsg, "%s", VG_(get_error_string)(e));
@@ -252,6 +267,8 @@ static UInt drd_tool_error_update_extra(Error* e)
     return sizeof(BarrierErrInfo);
   case RwlockErr:
     return sizeof(RwlockErrInfo);
+  case HoldtimeErr:
+    return sizeof(HoldtimeErrInfo);
   case GenericErr:
     return sizeof(GenericErrInfo);
   default:
@@ -280,6 +297,8 @@ static Bool drd_tool_error_recog(Char* const name, Supp* const supp)
     ;
   else if (VG_(strcmp)(name, STR_RwlockErr) == 0)
     ;
+  else if (VG_(strcmp)(name, STR_HoldtimeErr) == 0)
+    ;
   else if (VG_(strcmp)(name, STR_GenericErr) == 0)
     ;
   else
@@ -314,6 +333,7 @@ static Char* drd_tool_error_name(Error* e)
   case SemaphoreErr: return VGAPPEND(STR_, SemaphoreErr);
   case BarrierErr:   return VGAPPEND(STR_, BarrierErr);
   case RwlockErr:    return VGAPPEND(STR_, RwlockErr);
+  case HoldtimeErr:  return VGAPPEND(STR_, HoldtimeErr);
   case GenericErr:   return VGAPPEND(STR_, GenericErr);
   default:
     tl_assert(0);
index c9fa953dac3f7ec58537575885f19f88df83570c..fbff475d5959dcb061f011d194488c40ba9b44f5 100644 (file)
@@ -53,8 +53,10 @@ typedef enum {
    BarrierErr     = 7,
 #define STR_RwlockErr    "RwlockErr"
    RwlockErr      = 8,
+#define STR_HoldtimeErr  "HoldtimeErr"
+   HoldtimeErr    = 9,
 #define STR_GenericErr   "GenericErr"
-   GenericErr     = 9,
+   GenericErr     = 10,
 } DrdErrorKind;
 
 /* The classification of a faulting address. */
@@ -126,6 +128,13 @@ typedef struct {
    Addr rwlock;
 } RwlockErrInfo;
 
+typedef struct {
+  Addr        synchronization_object;
+  ExeContext* acquired_at;
+  UInt        hold_time_ms;
+  UInt        threshold_ms;
+} HoldtimeErrInfo;
+
 typedef struct {
 } GenericErrInfo;
 
index bdb13b5cac800e0dc71201d04d82cf957bf318e2..5ff2aace87807990efbb78b6158ca059186eec25 100644 (file)
@@ -74,41 +74,54 @@ static Bool s_show_stack_usage    = False;
 
 static Bool drd_process_cmd_line_option(Char* arg)
 {
-  int segment_merging   = -1;
-  int show_confl_seg    = -1;
-  int trace_barrier     = -1;
-  int trace_clientobj   = -1;
-  int trace_cond        = -1;
-  int trace_csw         = -1;
-  int trace_danger_set  = -1;
-  int trace_mutex       = -1;
-  int trace_rwlock      = -1;
-  int trace_segment     = -1;
-  int trace_semaphore   = -1;
-  int trace_suppression = -1;
-  Char* trace_address   = 0;
-
-  VG_BOOL_CLO     (arg, "--check-stack-var",   s_drd_check_stack_var)
-  else VG_BOOL_CLO(arg, "--drd-stats",         s_drd_print_stats)
-  else VG_BOOL_CLO(arg, "--segment-merging",   segment_merging)
-  else VG_BOOL_CLO(arg, "--show-confl-seg",    show_confl_seg)
-  else VG_BOOL_CLO(arg, "--show-stack-usage",  s_show_stack_usage)
-  else VG_BOOL_CLO(arg, "--trace-barrier",     trace_barrier)
-  else VG_BOOL_CLO(arg, "--trace-clientobj",   trace_clientobj)
-  else VG_BOOL_CLO(arg, "--trace-cond",        trace_cond)
-  else VG_BOOL_CLO(arg, "--trace-csw",         trace_csw)
-  else VG_BOOL_CLO(arg, "--trace-danger-set",  trace_danger_set)
-  else VG_BOOL_CLO(arg, "--trace-fork-join",   s_drd_trace_fork_join)
-  else VG_BOOL_CLO(arg, "--trace-mutex",       trace_mutex)
-  else VG_BOOL_CLO(arg, "--trace-rwlock",      trace_rwlock)
-  else VG_BOOL_CLO(arg, "--trace-segment",     trace_segment)
-  else VG_BOOL_CLO(arg, "--trace-semaphore",   trace_semaphore)
-  else VG_BOOL_CLO(arg, "--trace-suppr",       trace_suppression)
-  else VG_BOOL_CLO(arg, "--var-info",          s_drd_var_info)
-  else VG_STR_CLO (arg, "--trace-addr",        trace_address)
+  int exclusive_threshold_ms = -1;
+  int segment_merging     = -1;
+  int shared_threshold_ms    = -1;
+  int show_confl_seg      = -1;
+  int trace_barrier       = -1;
+  int trace_clientobj     = -1;
+  int trace_cond          = -1;
+  int trace_csw           = -1;
+  int trace_danger_set    = -1;
+  int trace_mutex         = -1;
+  int trace_rwlock        = -1;
+  int trace_segment       = -1;
+  int trace_semaphore     = -1;
+  int trace_suppression   = -1;
+  Char* trace_address     = 0;
+
+  VG_BOOL_CLO     (arg, "--check-stack-var",     s_drd_check_stack_var)
+  else VG_BOOL_CLO(arg, "--drd-stats",           s_drd_print_stats)
+  else VG_BOOL_CLO(arg, "--segment-merging",     segment_merging)
+  else VG_BOOL_CLO(arg, "--show-confl-seg",      show_confl_seg)
+  else VG_BOOL_CLO(arg, "--show-stack-usage",    s_show_stack_usage)
+  else VG_BOOL_CLO(arg, "--trace-barrier",       trace_barrier)
+  else VG_BOOL_CLO(arg, "--trace-clientobj",     trace_clientobj)
+  else VG_BOOL_CLO(arg, "--trace-cond",          trace_cond)
+  else VG_BOOL_CLO(arg, "--trace-csw",           trace_csw)
+  else VG_BOOL_CLO(arg, "--trace-danger-set",    trace_danger_set)
+  else VG_BOOL_CLO(arg, "--trace-fork-join",     s_drd_trace_fork_join)
+  else VG_BOOL_CLO(arg, "--trace-mutex",         trace_mutex)
+  else VG_BOOL_CLO(arg, "--trace-rwlock",        trace_rwlock)
+  else VG_BOOL_CLO(arg, "--trace-segment",       trace_segment)
+  else VG_BOOL_CLO(arg, "--trace-semaphore",     trace_semaphore)
+  else VG_BOOL_CLO(arg, "--trace-suppr",         trace_suppression)
+  else VG_BOOL_CLO(arg, "--var-info",            s_drd_var_info)
+  else VG_NUM_CLO (arg, "--exclusive-threshold", exclusive_threshold_ms)
+  else VG_NUM_CLO (arg, "--shared-threshold",    shared_threshold_ms)
+  else VG_STR_CLO (arg, "--trace-addr",          trace_address)
   else
     return VG_(replacement_malloc_process_cmd_line_option)(arg);
 
+  if (exclusive_threshold_ms != -1)
+  {
+    mutex_set_lock_threshold(exclusive_threshold_ms);
+    rwlock_set_exclusive_threshold(exclusive_threshold_ms);
+  }
+  if (shared_threshold_ms != -1)
+  {
+    rwlock_set_shared_threshold(shared_threshold_ms);
+  }
   if (segment_merging != -1)
     thread_set_segment_merging(segment_merging);
   if (show_confl_seg != -1)
@@ -147,11 +160,15 @@ static void drd_print_usage(void)
   VG_(printf)(
 "    --check-stack-var=yes|no  Whether or not to report data races on\n"
 "                              stack variables [no].\n"
+"    --exclusive-threshold=<n> Print an error message if any mutex or\n"
+"        writer lock is held longer than the specified time (in milliseconds).\n"
 "    --segment-merging=yes|no  Controls segment merging [yes].\n"
 "        Segment merging is an algorithm to limit memory usage of the\n"
 "        data race detection algorithm. Disabling segment merging may\n"
 "        improve the accuracy of the so-called 'other segments' displayed\n"
 "        in race reports but can also trigger an out of memory error.\n"
+"    --shared-threshold=<n>    Print an error message if a reader lock\n"
+"        is held longer than the specified time (in milliseconds).\n"
 "    --show-confl-seg=yes|no   Show conflicting segments in race reports [yes].\n"
 "    --show-stack-usage=yes|no Print stack usage at thread exit time [no].\n"
 "    --var-info=yes|no         Display the names of global, static and\n"
index dca84a74fee5e9a0841ac6c7d0a8f3dd3b128a20..dd009de1462bc95b9e27bd689dcbe3027d2b919a 100644 (file)
 #include "drd_error.h"
 #include "drd_mutex.h"
 #include "priv_drd_clientreq.h"
+#include "pub_tool_vki.h"
 #include "pub_tool_errormgr.h"    // VG_(maybe_record_error)()
 #include "pub_tool_libcassert.h"  // tl_assert()
 #include "pub_tool_libcbase.h"    // VG_(strlen)
 #include "pub_tool_libcprint.h"   // VG_(message)()
+#include "pub_tool_libcproc.h"    // VG_(read_millisecond_timer)()
 #include "pub_tool_machine.h"     // VG_(get_IP)()
 #include "pub_tool_threadstate.h" // VG_(get_running_tid)()
 
@@ -46,6 +48,7 @@ static Bool mutex_is_locked(struct mutex_info* const p);
 static Bool s_trace_mutex;
 static ULong s_mutex_lock_count;
 static ULong s_mutex_segment_creation_count;
+static UInt s_mutex_lock_threshold_ms = 1000 * 1000;
 
 
 // Function definitions.
@@ -56,6 +59,11 @@ void mutex_set_trace(const Bool trace_mutex)
   s_trace_mutex = trace_mutex;
 }
 
+void mutex_set_lock_threshold(const UInt lock_threshold_ms)
+{
+  s_mutex_lock_threshold_ms = lock_threshold_ms;
+}
+
 static
 void mutex_initialize(struct mutex_info* const p,
                       const Addr mutex, const MutexT mutex_type)
@@ -68,6 +76,8 @@ void mutex_initialize(struct mutex_info* const p,
   p->recursion_count     = 0;
   p->owner               = DRD_INVALID_THREADID;
   p->last_locked_segment = 0;
+  p->acquiry_time_ms     = 0;
+  p->acquired_at         = 0;
 }
 
 /** Deallocate the memory that was allocated by mutex_initialize(). */
@@ -287,7 +297,9 @@ void mutex_post_lock(const Addr mutex, const Bool took_lock,
     thread_new_segment(drd_tid);
     s_mutex_segment_creation_count++;
 
-    p->owner = drd_tid;
+    p->owner           = drd_tid;
+    p->acquiry_time_ms = VG_(read_millisecond_timer)();
+    p->acquired_at     = VG_(record_ExeContext)(VG_(get_running_tid)(), 0);
     s_mutex_lock_count++;
   }
   else if (p->owner != drd_tid)
@@ -302,14 +314,16 @@ void mutex_post_lock(const Addr mutex, const Bool took_lock,
   p->recursion_count++;
 }
 
-/**
- * Update mutex_info state when unlocking the pthread_mutex_t mutex.
- * Note: this function must be called before pthread_mutex_unlock() is called,
- * or a race condition is triggered !
- * @return New value of the mutex recursion count.
- * @param mutex Pointer to pthread_mutex_t data structure in the client space.
- * @param tid ThreadId of the thread calling pthread_mutex_unlock().
- * @param vc Pointer to the current vector clock of thread tid.
+/** Update mutex_info state when unlocking the pthread_mutex_t mutex.
+ *
+ *  @param mutex Pointer to pthread_mutex_t data structure in the client space.
+ *  @param tid ThreadId of the thread calling pthread_mutex_unlock().
+ *  @param vc Pointer to the current vector clock of thread tid.
+ *
+ *  @return New value of the mutex recursion count.
+ *
+ *  @note This function must be called before pthread_mutex_unlock() is called,
+ *        or a race condition is triggered !
  */
 void mutex_unlock(const Addr mutex, const MutexT mutex_type)
 {
@@ -370,12 +384,28 @@ void mutex_unlock(const Addr mutex, const MutexT mutex_type)
 
   if (p->recursion_count == 0)
   {
+    if (s_mutex_lock_threshold_ms > 0)
+    {
+      ULong held = VG_(read_millisecond_timer)() - p->acquiry_time_ms;
+      if (held > s_mutex_lock_threshold_ms)
+      {
+        HoldtimeErrInfo HEI
+          = { mutex, p->acquired_at, held, s_mutex_lock_threshold_ms };
+        VG_(maybe_record_error)(vg_tid,
+                                HoldtimeErr,
+                                VG_(get_IP)(vg_tid),
+                                "mutex",
+                                &HEI);
+      }
+    }
+
     /* This pthread_mutex_unlock() call really unlocks the mutex. Save the */
     /* current vector clock of the thread such that it is available when  */
     /* this mutex is locked again.                                        */
 
     thread_get_latest_segment(&p->last_locked_segment, drd_tid);
     thread_new_segment(drd_tid);
+    p->acquired_at = 0;
     s_mutex_segment_creation_count++;
   }
 }
index 77f24e941507ce835b76817b460f81f34804a442..3babae473ef390ba8a17c404851c5fba34266a79 100644 (file)
@@ -40,6 +40,7 @@ struct mutex_info;
 
 
 void mutex_set_trace(const Bool trace_mutex);
+void mutex_set_lock_threshold(const UInt lock_threshold_ms);
 struct mutex_info* mutex_init(const Addr mutex,
                               const MutexT mutex_type);
 void mutex_post_destroy(const Addr mutex);
index 46ac1999ca41dc02904d58bb198a11b9010c6acc..d70810fd328a765a977a55b53243f6149c25a71c 100644 (file)
 #include "drd_error.h"
 #include "drd_rwlock.h"
 #include "priv_drd_clientreq.h"
+#include "pub_tool_vki.h"
 #include "pub_tool_errormgr.h"    // VG_(maybe_record_error)()
 #include "pub_tool_libcassert.h"  // tl_assert()
 #include "pub_tool_libcprint.h"   // VG_(message)()
+#include "pub_tool_libcproc.h"    // VG_(read_millisecond_timer)()
 #include "pub_tool_machine.h"     // VG_(get_IP)()
 #include "pub_tool_mallocfree.h"  // VG_(malloc)(), VG_(free)()
 #include "pub_tool_threadstate.h" // VG_(get_running_tid)()
@@ -56,6 +58,8 @@ static ULong s_rwlock_segment_creation_count;
 // Local variables.
 
 static Bool s_trace_rwlock;
+static UInt s_exclusive_threshold_ms;
+static UInt s_shared_threshold_ms;
 
 
 // Function definitions.
@@ -66,6 +70,16 @@ void rwlock_set_trace(const Bool trace_rwlock)
   s_trace_rwlock = trace_rwlock;
 }
 
+void rwlock_set_exclusive_threshold(const UInt exclusive_threshold_ms)
+{
+  s_exclusive_threshold_ms = exclusive_threshold_ms;
+}
+
+void rwlock_set_shared_threshold(const UInt shared_threshold_ms)
+{
+  s_shared_threshold_ms = shared_threshold_ms;
+}
+
 static Bool rwlock_is_rdlocked(struct rwlock_info* p)
 {
   struct rwlock_thread_info* q;
@@ -166,8 +180,10 @@ void rwlock_initialize(struct rwlock_info* const p, const Addr rwlock)
   tl_assert(p->a1 == rwlock);
   tl_assert(p->type == ClientRwlock);
 
-  p->cleanup     = (void(*)(DrdClientobj*))&rwlock_cleanup;
-  p->thread_info = VG_(OSetGen_Create)(0, 0, VG_(malloc), VG_(free));
+  p->cleanup         = (void(*)(DrdClientobj*))&rwlock_cleanup;
+  p->thread_info     = VG_(OSetGen_Create)(0, 0, VG_(malloc), VG_(free));
+  p->acquiry_time_ms = 0;
+  p->acquired_at     = 0;
 }
 
 /** Deallocate the memory that was allocated by rwlock_initialize(). */
@@ -356,6 +372,9 @@ void rwlock_post_rdlock(const Addr rwlock, const Bool took_lock)
     q->last_lock_was_writer_lock = False;
     thread_new_segment(drd_tid);
     s_rwlock_segment_creation_count++;
+
+    p->acquiry_time_ms = VG_(read_millisecond_timer)();
+    p->acquired_at     = VG_(record_ExeContext)(VG_(get_running_tid)(), 0);
   }
 }
 
@@ -430,6 +449,8 @@ void rwlock_post_wrlock(const Addr rwlock, const Bool took_lock)
   rwlock_combine_other_vc(p, drd_tid, True);
   thread_new_segment(drd_tid);
   s_rwlock_segment_creation_count++;
+  p->acquiry_time_ms = VG_(read_millisecond_timer)();
+  p->acquired_at     = VG_(record_ExeContext)(VG_(get_running_tid)(), 0);
 }
 
 /**
@@ -471,11 +492,45 @@ void rwlock_pre_unlock(const Addr rwlock)
   q = lookup_or_insert_node(p->thread_info, drd_tid);
   tl_assert(q);
   if (q->reader_nesting_count > 0)
+  {
     q->reader_nesting_count--;
+    if (q->reader_nesting_count == 0 && s_shared_threshold_ms > 0)
+    {
+      ULong held = VG_(read_millisecond_timer)() - p->acquiry_time_ms;
+      if (held > s_shared_threshold_ms)
+      {
+        HoldtimeErrInfo HEI
+          = { rwlock, p->acquired_at, held, s_shared_threshold_ms };
+        VG_(maybe_record_error)(vg_tid,
+                                HoldtimeErr,
+                                VG_(get_IP)(vg_tid),
+                                "rwlock",
+                                &HEI);
+      }
+    }
+  }
   else if (q->writer_nesting_count > 0)
+  {
     q->writer_nesting_count--;
+    if (q->writer_nesting_count == 0 && s_exclusive_threshold_ms > 0)
+    {
+      ULong held = VG_(read_millisecond_timer)() - p->acquiry_time_ms;
+      if (held > s_exclusive_threshold_ms)
+      {
+        HoldtimeErrInfo HEI
+          = { rwlock, p->acquired_at, held, s_exclusive_threshold_ms };
+        VG_(maybe_record_error)(vg_tid,
+                                HoldtimeErr,
+                                VG_(get_IP)(vg_tid),
+                                "rwlock",
+                                &HEI);
+      }
+    }
+  }
   else
+  {
     tl_assert(False);
+  }
 
   if (q->reader_nesting_count == 0 && q->writer_nesting_count == 0)
   {
index 77e3abfe67e9004946b33581f51b52478e522ae6..6afcd5d52bd9a118d64fa8947bec3f0b407deb1d 100644 (file)
@@ -40,6 +40,8 @@ struct rwlock_info;
 
 
 void rwlock_set_trace(const Bool trace_rwlock);
+void rwlock_set_exclusive_threshold(const UInt exclusive_threshold_ms);
+void rwlock_set_shared_threshold(const UInt shared_threshold_ms);
 struct rwlock_info* rwlock_pre_init(const Addr rwlock);
 void rwlock_post_destroy(const Addr rwlock);
 void rwlock_pre_rdlock(const Addr rwlock);