From 7317d9499b9de3c5db06c0b6b7053764c2ccf353 Mon Sep 17 00:00:00 2001 From: Kostya Serebryany Date: Fri, 21 Mar 2014 11:37:43 +0000 Subject: [PATCH] [sanitizer] more human-readable deadlock reports llvm-svn: 204454 --- compiler-rt/lib/tsan/rtl/tsan_report.cc | 42 ++++++++++++++----- compiler-rt/lib/tsan/rtl/tsan_rtl_mutex.cc | 2 +- .../tsan/deadlock_detector_stress_test.cc | 26 ++++++------ 3 files changed, 46 insertions(+), 24 deletions(-) diff --git a/compiler-rt/lib/tsan/rtl/tsan_report.cc b/compiler-rt/lib/tsan/rtl/tsan_report.cc index 45e27750a036..14c09df26036 100644 --- a/compiler-rt/lib/tsan/rtl/tsan_report.cc +++ b/compiler-rt/lib/tsan/rtl/tsan_report.cc @@ -162,6 +162,12 @@ static void PrintMutexShort(const ReportMutex *rm, const char *after) { Printf("%sM%zd%s%s", d.Mutex(), rm->id, d.EndMutex(), after); } +static void PrintMutexShortWitAddress(const ReportMutex *rm, + const char *after) { + Decorator d; + Printf("%sM%zd (%p)%s%s", d.Mutex(), rm->id, rm->addr, d.EndMutex(), after); +} + static void PrintMutex(const ReportMutex *rm) { Decorator d; if (rm->destroyed) { @@ -231,18 +237,30 @@ void PrintReport(const ReportDesc *rep) { Printf("%s", d.EndWarning()); if (rep->typ == ReportTypeDeadlock) { - Printf(" Path: "); - CHECK_GT(rep->mutexes.Size(), 0U); - CHECK_EQ(rep->mutexes.Size() * 2, rep->stacks.Size()); + Printf(" Cycle in lock order graph: "); for (uptr i = 0; i < rep->mutexes.Size(); i++) - PrintMutexShort(rep->mutexes[i], " => "); + PrintMutexShortWitAddress(rep->mutexes[i], " => "); PrintMutexShort(rep->mutexes[0], "\n\n"); + CHECK_GT(rep->mutexes.Size(), 0U); + CHECK_EQ(rep->mutexes.Size() * (flags()->second_deadlock_stack ? 2 : 1), + rep->stacks.Size()); for (uptr i = 0; i < rep->mutexes.Size(); i++) { - Printf(" Edge: "); - PrintMutexShort(rep->mutexes[i], " => "); - PrintMutexShort(rep->mutexes[(i+1) % rep->mutexes.Size()], "\n"); - PrintStack(rep->stacks[2*i]); - PrintStack(rep->stacks[2*i+1]); + Printf(" Mutex "); + PrintMutexShort(rep->mutexes[(i + 1) % rep->mutexes.Size()], + " acquired here while holding mutex "); + PrintMutexShort(rep->mutexes[i], ":\n"); + if (flags()->second_deadlock_stack) { + PrintStack(rep->stacks[2*i]); + Printf(" Mutex "); + PrintMutexShort(rep->mutexes[i], + " previously acquired by the same thread here:\n"); + PrintStack(rep->stacks[2*i+1]); + } else { + PrintStack(rep->stacks[i]); + if (i == 0) + Printf(" Hint: use TSAN_OPTIONS=second_deadlock_stack=1 " + "to get more informative warning message\n\n"); + } } } else { for (uptr i = 0; i < rep->stacks.Size(); i++) { @@ -261,8 +279,10 @@ void PrintReport(const ReportDesc *rep) { for (uptr i = 0; i < rep->locs.Size(); i++) PrintLocation(rep->locs[i]); - for (uptr i = 0; i < rep->mutexes.Size(); i++) - PrintMutex(rep->mutexes[i]); + if (rep->typ != ReportTypeDeadlock) { + for (uptr i = 0; i < rep->mutexes.Size(); i++) + PrintMutex(rep->mutexes[i]); + } for (uptr i = 0; i < rep->threads.Size(); i++) PrintThread(rep->threads[i]); diff --git a/compiler-rt/lib/tsan/rtl/tsan_rtl_mutex.cc b/compiler-rt/lib/tsan/rtl/tsan_rtl_mutex.cc index a582b25488da..7b52a93af178 100644 --- a/compiler-rt/lib/tsan/rtl/tsan_rtl_mutex.cc +++ b/compiler-rt/lib/tsan/rtl/tsan_rtl_mutex.cc @@ -417,7 +417,7 @@ void ReportDeadlock(ThreadState *thr, uptr pc, DDReport *r) { uptr dummy_pc = 0x42; for (int i = 0; i < r->n; i++) { uptr size; - for (int j = 0; j < 2; j++) { + for (int j = 0; j < (flags()->second_deadlock_stack ? 2 : 1); j++) { u32 stk = r->loop[i].stk[j]; if (stk) { const uptr *trace = StackDepotGet(stk, &size); diff --git a/compiler-rt/test/tsan/deadlock_detector_stress_test.cc b/compiler-rt/test/tsan/deadlock_detector_stress_test.cc index 14b4f8fee38b..1b7d1f60266b 100644 --- a/compiler-rt/test/tsan/deadlock_detector_stress_test.cc +++ b/compiler-rt/test/tsan/deadlock_detector_stress_test.cc @@ -152,17 +152,18 @@ class LockTest { Lock_0_1(); Lock_1_0(); // CHECK: WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) - // CHECK: Path: [[M1:M[0-9]+]] => [[M2:M[0-9]+]] => [[M1]] - // CHECK: Edge: [[M1]] => [[M2]] + // CHECK: Cycle in lock order graph: [[M1:M[0-9]+]] ([[A1]]) => [[M2:M[0-9]+]] ([[A2]]) => [[M1]] + // CHECK: Mutex [[M2]] acquired here while holding mutex [[M1]] // CHECK: #0 pthread_ + // CHECK-SECOND: Mutex [[M1]] previously acquired by the same thread here: + // CHECK-SECOND: #0 pthread_ + // CHECK-NOT-SECOND: second_deadlock_stack=1 to get more informative warning message + // CHECK-NOT-SECOND-NOT: #0 pthread_ + // CHECK: Mutex [[M1]] acquired here while holding mutex [[M2]] + // CHECK: #0 pthread_ + // CHECK-SECOND: Mutex [[M2]] previously acquired by the same thread here: // CHECK-SECOND: #0 pthread_ // CHECK-NOT-SECOND-NOT: #0 pthread_ - // CHECK: Edge: [[M2]] => [[M1]] - // CHECK: #0 pthread_ - // CHECK-SECOND: #0 pthread_ - // CHECK-NOT-SECOND-NOT: #0 pthread_ - // CHECK: Mutex [[M1]] ([[A1]]) created at: - // CHECK: Mutex [[M2]] ([[A2]]) created at: // CHECK-NOT: WARNING: ThreadSanitizer: } @@ -178,10 +179,7 @@ class LockTest { Lock2(1, 2); Lock2(2, 0); // CHECK: WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) - // CHECK: Path: [[M1:M[0-9]+]] => [[M2:M[0-9]+]] => [[M3:M[0-9]+]] => [[M1]] - // CHECK: Mutex [[M1]] ([[A1]]) created at: - // CHECK: Mutex [[M2]] ([[A2]]) created at: - // CHECK: Mutex [[M3]] ([[A3]]) created at: + // CHECK: Cycle in lock order graph: [[M1:M[0-9]+]] ([[A1]]) => [[M2:M[0-9]+]] ([[A2]]) => [[M3:M[0-9]+]] ([[A3]]) => [[M1]] // CHECK-NOT: WARNING: ThreadSanitizer: } @@ -426,12 +424,16 @@ class LockTest { fprintf(stderr, "Starting Test16: detailed output test with two locks\n"); // CHECK: Starting Test16 // CHECK: WARNING: ThreadSanitizer: lock-order-inversion + // CHECK: acquired here while holding mutex // CHECK: LockTest::Acquire1 // CHECK-NEXT: LockTest::Acquire_0_then_1 + // CHECK-SECOND: previously acquired by the same thread here // CHECK-SECOND: LockTest::Acquire0 // CHECK-SECOND-NEXT: LockTest::Acquire_0_then_1 + // CHECK: acquired here while holding mutex // CHECK: LockTest::Acquire0 // CHECK-NEXT: LockTest::Acquire_1_then_0 + // CHECK-SECOND: previously acquired by the same thread here // CHECK-SECOND: LockTest::Acquire1 // CHECK-SECOND-NEXT: LockTest::Acquire_1_then_0 Init(5);