Use sched_yield in Monitor::MonitorEnter.

Previously we used NanoSleep(1000), but this was unreliable. It could
result in waiting for >= 40ms instead of 1us. Since this was in a loop
it was especially bad if the GC was trying to suspend all the
threads when we were sleeping. This resulted in thread suspension
occasionally taking longer than a second.
Results on the provided picasso-sample app on Nexus 5:
Longest GC pause before: ~1.5s.
Longest GC pause after: <5ms.

Also added a warning if thread suspension takes longer than a
threshold (currently 5ms).

Bug: 16307460
External bug: https://code.google.com/p/android-developer-preview/issues/detail?id=367

(cherry picked from commit 251755cd511463260e60be98bf138b6aa1c14bf3)

Change-Id: I491c0799cc23ee6e68abc1bf77d1f0f4263e8ef5

diff --git a/runtime/monitor.cc b/runtime/monitor.cc
index 5633a77..da481e4 100644 (file)
--- a/runtime/monitor.cc
+++ b/runtime/monitor.cc
@@ -746,7 +746,11 @@ mirror::Object* Monitor::MonitorEnter(Thread* self, mirror::Object* obj) {
           contention_count++;
           Runtime* runtime = Runtime::Current();
           if (contention_count <= runtime->GetMaxSpinsBeforeThinkLockInflation()) {
-            NanoSleep(1000);  // Sleep for 1us and re-attempt.
+            // TODO: Consider switch thread state to kBlocked when we are yielding.
+            // Use sched_yield instead of NanoSleep since NanoSleep can wait much longer than the
+            // parameter you pass in. This can cause thread suspension to take excessively long
+            // make long pauses. See b/16307460.
+            sched_yield();
           } else {
             contention_count = 0;
             InflateThinLocked(self, h_obj, lock_word, 0);

diff --git a/runtime/thread_list.cc b/runtime/thread_list.cc
index 54732fa..b649b62 100644 (file)
--- a/runtime/thread_list.cc
+++ b/runtime/thread_list.cc
@@ -39,6 +39,8 @@
 
 namespace art {
 
+static constexpr uint64_t kLongThreadSuspendThreshold = MsToNs(5);
+
 ThreadList::ThreadList()
     : suspend_all_count_(0), debug_suspend_all_count_(0),
       thread_exit_cond_("thread exit condition variable", *Locks::thread_list_lock_) {
@@ -304,8 +306,8 @@ void ThreadList::SuspendAll() {
   DCHECK(self != nullptr);
 
   VLOG(threads) << *self << " SuspendAll starting...";
-
   ATRACE_BEGIN("Suspending mutator threads");
+  uint64_t start_time = NanoTime();
 
   Locks::mutator_lock_->AssertNotHeld(self);
   Locks::thread_list_lock_->AssertNotHeld(self);
@@ -338,6 +340,11 @@ void ThreadList::SuspendAll() {
   Locks::mutator_lock_->ExclusiveLock(self);
 #endif
 
+  uint64_t end_time = NanoTime();
+  if (end_time - start_time > kLongThreadSuspendThreshold) {
+    LOG(WARNING) << "Suspending all threads took: " << PrettyDuration(end_time - start_time);
+  }
+
   if (kDebugLocking) {
     // Debug check that all threads are suspended.
     AssertThreadsAreSuspended(self, self);