From b9001abff3a45f1ae90536da7dd1ec28a6ae0174 Mon Sep 17 00:00:00 2001 From: Mathieu Chartier Date: Fri, 3 Oct 2014 13:28:46 -0700 Subject: [PATCH] Add extra logging for lock contention When we get contention which is longer than kLongWaitMs (= 100ms) we log to logcat. Example output: W/art ( 9960): Long monitor contention event with owner method=void com.android.server.am.BroadcastQueue.processNextBroadcast(boolean) from BroadcastQueue.java:542 waiters=1 for 243ms Bug: 17787391 Change-Id: Id1f92d9c41ec909d221871ecc2ff6181dcec2ed4 --- runtime/monitor.cc | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/runtime/monitor.cc b/runtime/monitor.cc index 03f86874b..0cf077a40 100644 --- a/runtime/monitor.cc +++ b/runtime/monitor.cc @@ -36,6 +36,8 @@ namespace art { +static constexpr uint64_t kLongWaitMs = 100; + /* * Every Object has a monitor associated with it, but not every Object is actually locked. Even * the ones that are locked do not need a full-fledged monitor until a) there is actual contention @@ -250,6 +252,7 @@ void Monitor::Lock(Thread* self) { mirror::ArtMethod* owners_method = locking_method_; uint32_t owners_dex_pc = locking_dex_pc_; // Do this before releasing the lock so that we don't get deflated. + size_t num_waiters = num_waiters_; ++num_waiters_; monitor_lock_.Unlock(self); // Let go of locks in order. self->SetMonitorEnterObject(GetObject()); @@ -271,6 +274,12 @@ void Monitor::Lock(Thread* self) { const char* owners_filename; uint32_t owners_line_number; TranslateLocation(owners_method, owners_dex_pc, &owners_filename, &owners_line_number); + if (wait_ms > kLongWaitMs && owners_method != nullptr) { + LOG(WARNING) << "Long monitor contention event with owner method=" + << PrettyMethod(owners_method) << " from " << owners_filename << ":" + << owners_line_number << " waiters=" << num_waiters << " for " + << PrettyDuration(MsToNs(wait_ms)); + } LogContentionEvent(self, wait_ms, sample_percent, owners_filename, owners_line_number); } } -- 2.11.0