commit ff7380681c50129ff689a11ac0f49512b4be7295
author Elliott Hughes <enh@google.com> Fri Feb 03 15:00:42 2012 -0800
committer Elliott Hughes <enh@google.com> Fri Feb 03 15:07:35 2012 -0800
tree 79704a4b85026aae58c17780cd88377e8d5a3c08
parent 9ada79cbe875dbcf7229b3f563303d21b0537d5f

Fix a thread suspend timeout, and improve the diagnostics for thread suspend timeouts.

I still needed gdb to understand this, but when we dump _native_ stacks, the
additional diagnostics here will be more helpful. (They're somewhat helpful
anyway, in that they let you see the state all threads are in. Also, in a
started runtime rather than the compiler, threads will have informative managed
stacks.)

Also make the apparent duplication in the dex2oat timings clearer, and only
include time spent on resolving strings if we resolved any strings.

Change-Id: Icd469d9b085171ebb2dede2afb5140387cd3240c

src/compiler.cc

diff --git a/src/compiler.cc b/src/compiler.cc
index 41d2f6a..4cc228c 100644
--- a/src/compiler.cc
+++ b/src/compiler.cc
@@ -306,6 +306,8 @@
   }
 
   ~Workers() {
+    // Switch to kVmWait while we're blocked waiting for the other threads to finish.
+    ScopedThreadStateChange tsc(Thread::Current(), Thread::kVmWait);
     STLDeleteElements(&threads_);
   }
 
@@ -402,8 +404,8 @@
     for (size_t string_idx = 0; string_idx < dex_cache->NumStrings(); string_idx++) {
       class_linker->ResolveString(dex_file, string_idx, dex_cache);
     }
+    timings.AddSplit("Resolve " + dex_file.GetLocation() + " Strings");
   }
-  timings.AddSplit("Resolve.Strings");
 
   Context context;
   context.class_linker = class_linker;
@@ -414,12 +416,12 @@
   {
     Workers workers(&context, 0, dex_cache->NumResolvedTypes(), ResolveType);
   }
-  timings.AddSplit("Resolve.Types");
+  timings.AddSplit("Resolve " + dex_file.GetLocation() + " Types");
 
   {
     Workers workers(&context, 0, dex_file.NumClassDefs(), ResolveClassFieldsAndMethods);
   }
-  timings.AddSplit("Resolve.MethodsAndFields");
+  timings.AddSplit("Resolve " + dex_file.GetLocation() + " MethodsAndFields");
 }
 
 void Compiler::Verify(const ClassLoader* class_loader,

src/thread.cc

diff --git a/src/thread.cc b/src/thread.cc
index 54b17d0..6c8e1bb 100644
--- a/src/thread.cc
+++ b/src/thread.cc
@@ -659,6 +659,16 @@
   return ANNOTATE_UNPROTECTED_READ(suspend_count_) != 0 && GetState() != Thread::kRunnable;
 }
 
+static void ReportThreadSuspendTimeout(Thread* waiting_thread) {
+  Runtime* runtime = Runtime::Current();
+  std::ostringstream ss;
+  ss << "Thread suspend timeout; waiting thread=" << *waiting_thread << "\n";
+  runtime->DumpLockHolders(ss);
+  ss << "\n";
+  runtime->GetThreadList()->DumpLocked(ss);
+  LOG(FATAL) << ss.str();
+}
+
 void Thread::WaitUntilSuspended() {
   static const useconds_t kTimeoutUs = 30 * 1000000; // 30s.
 
@@ -666,7 +676,7 @@
   useconds_t delay = 0;
   while (GetState() == Thread::kRunnable) {
     if (total_delay >= kTimeoutUs) {
-      Runtime::Current()->DumpLockHolders(LOG(FATAL) << "Thread suspend timeout: " << *this << "\n");
+      ReportThreadSuspendTimeout(this);
     }
     useconds_t new_delay = delay * 2;
     CHECK_GE(new_delay, delay);

src/thread_list.cc

diff --git a/src/thread_list.cc b/src/thread_list.cc
index 57a2124..f344e67 100644
--- a/src/thread_list.cc
+++ b/src/thread_list.cc
@@ -89,6 +89,10 @@
 
 void ThreadList::Dump(std::ostream& os) {
   ScopedThreadListLock thread_list_lock;
+  DumpLocked(os);
+}
+
+void ThreadList::DumpLocked(std::ostream& os) {
   os << "DALVIK THREADS (" << list_.size() << "):\n";
   for (It it = list_.begin(), end = list_.end(); it != end; ++it) {
     (*it)->Dump(os);

src/thread_list.h

diff --git a/src/thread_list.h b/src/thread_list.h
index eb08401..02357fc 100644
--- a/src/thread_list.h
+++ b/src/thread_list.h
@@ -32,6 +32,7 @@
   ~ThreadList();
 
   void Dump(std::ostream& os);
+  void DumpLocked(std::ostream& os); // For thread suspend timeout dumps.
   pid_t GetLockOwner(); // For SignalCatcher.
 
   // Thread suspension support.