mesos-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From vinodk...@apache.org
Subject [17/23] git commit: Added timing information to Scheduler and Executor callbacks when verbose logging is enabled.
Date Tue, 13 Aug 2013 19:50:01 GMT
Added timing information to Scheduler and Executor callbacks when
verbose logging is enabled.

Review: https://reviews.apache.org/r/12520


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

Branch: refs/heads/vinod/0.13.0
Commit: f5a8c59edf9914adfee180ac8397452da667704a
Parents: a6a2fe9
Author: Benjamin Mahler <bmahler@twitter.com>
Authored: Fri Jul 12 13:57:34 2013 -0700
Committer: Benjamin Mahler <bmahler@twitter.com>
Committed: Fri Jul 12 16:21:45 2013 -0700

----------------------------------------------------------------------
 src/exec/exec.cpp   | 60 ++++++++++++++++++++++++++++++++++++++++
 src/sched/sched.cpp | 71 ++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 131 insertions(+)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/mesos/blob/f5a8c59e/src/exec/exec.cpp
----------------------------------------------------------------------
diff --git a/src/exec/exec.cpp b/src/exec/exec.cpp
index 116168f..d467724 100644
--- a/src/exec/exec.cpp
+++ b/src/exec/exec.cpp
@@ -39,6 +39,7 @@
 #include <stout/numify.hpp>
 #include <stout/option.hpp>
 #include <stout/os.hpp>
+#include <stout/stopwatch.hpp>
 #include <stout/stringify.hpp>
 #include <stout/uuid.hpp>
 
@@ -194,7 +195,15 @@ protected:
     VLOG(1) << "Executor registered on slave " << slaveId;
 
     connected = true;
+
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     executor->registered(driver, executorInfo, frameworkInfo, slaveInfo);
+
+    VLOG(1) << "Executor::registered took " << stopwatch.elapsed();
   }
 
   void reregistered(const SlaveID& slaveId, const SlaveInfo& slaveInfo)
@@ -207,7 +216,14 @@ protected:
 
     VLOG(1) << "Executor re-registered on slave " << slaveId;
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     executor->reregistered(driver, slaveInfo);
+
+    VLOG(1) << "Executor::reregistered took " << stopwatch.elapsed();
   }
 
   void reconnect(const SlaveID& slaveId)
@@ -257,7 +273,14 @@ protected:
 
     VLOG(1) << "Executor asked to run task '" << task.task_id() << "'";
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     executor->launchTask(driver, task);
+
+    VLOG(1) << "Executor::launchTask took " << stopwatch.elapsed();
   }
 
   void killTask(const TaskID& taskId)
@@ -270,7 +293,14 @@ protected:
 
     VLOG(1) << "Executor asked to kill task '" << taskId << "'";
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     executor->killTask(driver, taskId);
+
+    VLOG(1) << "Executor::killTask took " << stopwatch.elapsed();
   }
 
   void statusUpdateAcknowledgement(
@@ -310,7 +340,14 @@ protected:
 
     VLOG(1) << "Executor received framework message";
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     executor->frameworkMessage(driver, data);
+
+    VLOG(1) << "Executor::frameworkMessage took " << stopwatch.elapsed();
   }
 
   void shutdown()
@@ -327,8 +364,16 @@ protected:
       spawn(new ShutdownProcess(), true);
     }
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     // TODO(benh): Any need to invoke driver.stop?
     executor->shutdown(driver);
+
+    VLOG(1) << "Executor::shutdown took " << stopwatch.elapsed();
+
     aborted = true; // To make sure not to accept any new messages.
 
     if (local) {
@@ -365,8 +410,16 @@ protected:
       spawn(new ShutdownProcess(), true);
     }
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     // TODO: Pass an argument to shutdown to tell it this is abnormal?
     executor->shutdown(driver);
+
+    VLOG(1) << "Executor::shutdown took " << stopwatch.elapsed();
+
     aborted = true; // To make sure not to accept any new messages.
 
     // This is a pretty bad state ... no slave is left. Rather
@@ -387,8 +440,15 @@ protected:
 
       driver->abort();
 
+      Stopwatch stopwatch;
+      if (FLAGS_v >= 1) {
+        stopwatch.start();
+      }
+
       executor->error(driver, "Attempted to send TASK_STAGING status update");
 
+      VLOG(1) << "Executor::error took " << stopwatch.elapsed();
+
       return;
     }
 

http://git-wip-us.apache.org/repos/asf/mesos/blob/f5a8c59e/src/sched/sched.cpp
----------------------------------------------------------------------
diff --git a/src/sched/sched.cpp b/src/sched/sched.cpp
index 248e12e..8e60336 100644
--- a/src/sched/sched.cpp
+++ b/src/sched/sched.cpp
@@ -43,6 +43,7 @@
 #include <stout/flags.hpp>
 #include <stout/hashmap.hpp>
 #include <stout/os.hpp>
+#include <stout/stopwatch.hpp>
 #include <stout/uuid.hpp>
 
 #include "common/lock.hpp"
@@ -182,7 +183,14 @@ protected:
     // If master failed over, inform the scheduler about the
     // disconnection.
     if (connected) {
+      Stopwatch stopwatch;
+      if (FLAGS_v >= 1) {
+        stopwatch.start();
+      }
+
       scheduler->disconnected(driver);
+
+      VLOG(1) << "Scheduler::disconnected took " << stopwatch.elapsed();
     }
 
     connected = false;
@@ -196,7 +204,14 @@ protected:
     // Inform the scheduler about the disconnection if the driver
     // was previously registered with the master.
     if (connected) {
+      Stopwatch stopwatch;
+      if (FLAGS_v >= 1) {
+        stopwatch.start();
+      }
+
       scheduler->disconnected(driver);
+
+      VLOG(1) << "Scheduler::disconnected took " << stopwatch.elapsed();
     }
 
     // In this case, we don't actually invoke Scheduler::error
@@ -226,7 +241,14 @@ protected:
     connected = true;
     failover = false;
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->registered(driver, frameworkId, masterInfo);
+
+    VLOG(1) << "Scheduler::registered took " << stopwatch.elapsed();
   }
 
   void reregistered(const FrameworkID& frameworkId, const MasterInfo& masterInfo)
@@ -250,7 +272,14 @@ protected:
     connected = true;
     failover = false;
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->reregistered(driver, masterInfo);
+
+    VLOG(1) << "Scheduler::reregistered took " << stopwatch.elapsed();
   }
 
   void doReliableRegistration()
@@ -301,7 +330,14 @@ protected:
       }
     }
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->resourceOffers(driver, offers);
+
+    VLOG(1) << "Scheduler::resourceOffers took " << stopwatch.elapsed();
   }
 
   void rescindOffer(const OfferID& offerId)
@@ -316,7 +352,14 @@ protected:
 
     savedOffers.erase(offerId);
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->offerRescinded(driver, offerId);
+
+    VLOG(1) << "Scheduler::offerRescinded took " << stopwatch.elapsed();
   }
 
   void statusUpdate(const StatusUpdate& update, const UPID& pid)
@@ -342,8 +385,15 @@ protected:
     // multiple times (of course, if a scheduler re-uses a TaskID,
     // that could be bad.
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->statusUpdate(driver, status);
 
+    VLOG(1) << "Scheduler::statusUpdate took " << stopwatch.elapsed();
+
     // Acknowledge the status update.
     // NOTE: We do a dispatch here instead of directly sending the ACK because,
     // we want to avoid sending the ACK if the driver was aborted when we
@@ -390,7 +440,14 @@ protected:
 
     savedSlavePids.erase(slaveId);
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->slaveLost(driver, slaveId);
+
+    VLOG(1) << "Scheduler::slaveLost took " << stopwatch.elapsed();
   }
 
   void frameworkMessage(const SlaveID& slaveId,
@@ -405,7 +462,14 @@ protected:
 
     VLOG(1) << "Received framework message";
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->frameworkMessage(driver, executorId, slaveId, data);
+
+    VLOG(1) << "Scheduler::frameworkMessage took " << stopwatch.elapsed();
   }
 
   void error(const string& message)
@@ -419,7 +483,14 @@ protected:
 
     driver->abort();
 
+    Stopwatch stopwatch;
+    if (FLAGS_v >= 1) {
+      stopwatch.start();
+    }
+
     scheduler->error(driver, message);
+
+    VLOG(1) << "Scheduler::error took " << stopwatch.elapsed();
   }
 
   void stop(bool failover)


Mime
View raw message