From d6bb5c34d02c1caba72a45804e8a4e9cbf63993f Mon Sep 17 00:00:00 2001 From: Bart Van Assche Date: Sat, 28 Jun 2008 13:40:41 +0000 Subject: [PATCH] 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 --- exp-drd/drd_clientobj.h | 1 + exp-drd/drd_error.c | 52 ++++++++++++++------ exp-drd/drd_mutex.c | 2 + exp-drd/drd_mutex.h | 3 -- exp-drd/tests/pth_cond_race.stderr.exp | 5 +- exp-drd/tests/tc23_bogus_condwait.stderr.exp | 14 ++++-- 6 files changed, 54 insertions(+), 23 deletions(-) diff --git a/exp-drd/drd_clientobj.h b/exp-drd/drd_clientobj.h index 0068dc33d7..b8297b7f11 100644 --- a/exp-drd/drd_clientobj.h +++ b/exp-drd/drd_clientobj.h @@ -66,6 +66,7 @@ struct mutex_info 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 e4f35815b6..842a6379dc 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 @@ void set_show_conflicting_segments(const Bool scs) 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 @@ void describe_malloced_addr(Addr const a, SizeT const len, AddrInfo* const ai) } } +/** 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 @@ static void drd_tool_error_pp(Error* const e) 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 @@ static void drd_tool_error_pp(Error* const e) 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 dd009de146..823da1cd5b 100644 --- a/exp-drd/drd_mutex.c +++ b/exp-drd/drd_mutex.c @@ -77,6 +77,7 @@ void mutex_initialize(struct mutex_info* const p, 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 @@ static void mutex_cleanup(struct mutex_info* p) 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 3babae473e..e241f673fc 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 6cea56a3b9..8e38ee6eb9 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 b64e170388..7ce65f2c9c 100644 --- a/exp-drd/tests/tc23_bogus_condwait.stderr.exp +++ b/exp-drd/tests/tc23_bogus_condwait.stderr.exp @@ -4,7 +4,7 @@ The object at address 0x........ is not a mutex. 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 @@ Mutex not locked: mutex 0x........, recursion count 0, owner 0. 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 @@ The object at address 0x........ is not a mutex. 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 @@ Mutex not locked by calling thread: mutex 0x........, recursion count 1, owner 2 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: -- 2.47.2