kudu-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From t...@apache.org
Subject [1/2] incubator-kudu git commit: KUDU-1282. Add more logging on slow thread startup
Date Wed, 06 Jan 2016 23:45:51 GMT
Repository: incubator-kudu
Updated Branches:
  refs/heads/master 63b9268f9 -> bf1f244fb


KUDU-1282. Add more logging on slow thread startup

We've seen a few cases where threads are taking >500ms to start,
but it's not clear whether it's the pthread call itself, or
something to do with our Kudu threading wrapper.

This patch adds some more log messages for slow thread startup
to try to pinpoint the issue.

Change-Id: I89b2446f8107e7f1647f079f9ab97fd2d57ee921
Reviewed-on: http://gerrit.cloudera.org:8080/1651
Tested-by: Internal Jenkins
Reviewed-by: Jean-Daniel Cryans


Project: http://git-wip-us.apache.org/repos/asf/incubator-kudu/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-kudu/commit/f85ee5fe
Tree: http://git-wip-us.apache.org/repos/asf/incubator-kudu/tree/f85ee5fe
Diff: http://git-wip-us.apache.org/repos/asf/incubator-kudu/diff/f85ee5fe

Branch: refs/heads/master
Commit: f85ee5fed915122755f68b49668868758dc11059
Parents: 63b9268
Author: Todd Lipcon <todd@cloudera.com>
Authored: Wed Dec 16 16:19:30 2015 -0800
Committer: Jean-Daniel Cryans <jdcryans@gerrit.cloudera.org>
Committed: Tue Jan 5 19:06:21 2016 +0000

----------------------------------------------------------------------
 src/kudu/util/thread.cc | 20 ++++++++++++++------
 1 file changed, 14 insertions(+), 6 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/incubator-kudu/blob/f85ee5fe/src/kudu/util/thread.cc
----------------------------------------------------------------------
diff --git a/src/kudu/util/thread.cc b/src/kudu/util/thread.cc
index 7dcfc98..bac0dd3 100644
--- a/src/kudu/util/thread.cc
+++ b/src/kudu/util/thread.cc
@@ -432,9 +432,13 @@ Status Thread::StartThread(const std::string& category, const std::string&
name,
 
   // Temporary reference for the duration of this function.
   scoped_refptr<Thread> t(new Thread(category, name, functor));
-  int ret = pthread_create(&t->thread_, NULL, &Thread::SuperviseThread, t.get());
-  if (ret) {
-    return Status::RuntimeError("Could not create thread", strerror(ret), ret);
+
+  {
+    SCOPED_LOG_SLOW_EXECUTION_PREFIX(WARNING, 500 /* ms */, log_prefix, "creating pthread");
+    int ret = pthread_create(&t->thread_, NULL, &Thread::SuperviseThread, t.get());
+    if (ret) {
+      return Status::RuntimeError("Could not create thread", strerror(ret), ret);
+    }
   }
 
   // The thread has been created and is now joinable.
@@ -457,9 +461,13 @@ Status Thread::StartThread(const std::string& category, const std::string&
name,
   // 3. <value>: both the parent and the child are free to continue. If the
   //    value is INVALID_TID, the child could not discover its tid.
   Release_Store(&t->tid_, PARENT_WAITING_TID);
-  int loop_count = 0;
-  while (Acquire_Load(&t->tid_) == PARENT_WAITING_TID) {
-    boost::detail::yield(loop_count++);
+  {
+    SCOPED_LOG_SLOW_EXECUTION_PREFIX(WARNING, 500 /* ms */, log_prefix,
+                                     "waiting for new thread to publish its TID");
+    int loop_count = 0;
+    while (Acquire_Load(&t->tid_) == PARENT_WAITING_TID) {
+      boost::detail::yield(loop_count++);
+    }
   }
 
   VLOG(2) << "Started thread " << t->tid()<< " - " << category
<< ":" << name;


Mime
View raw message