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
diff --git a/runtime/monitor.cc b/runtime/monitor.cc
index 03f8687..0cf077a 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 @@
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 @@
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);
}
}