Repository: mesos Updated Branches: refs/heads/master d0446b7ea -> e46e16a4b
Added batch sizes and timings to the Registrar logging. Review: https://reviews.apache.org/r/26535 Project: http://git-wip-us.apache.org/repos/asf/mesos/repo Commit: http://git-wip-us.apache.org/repos/asf/mesos/commit/e46e16a4 Tree: http://git-wip-us.apache.org/repos/asf/mesos/tree/e46e16a4 Diff: http://git-wip-us.apache.org/repos/asf/mesos/diff/e46e16a4 Branch: refs/heads/master Commit: e46e16a4b0e6a548bf215feeaf69b0856f6682ff Parents: d0446b7 Author: Benjamin Mahler <[email protected]> Authored: Thu Oct 9 18:43:06 2014 -0700 Committer: Benjamin Mahler <[email protected]> Committed: Fri Oct 10 11:20:53 2014 -0700 ---------------------------------------------------------------------- src/master/registrar.cpp | 33 +++++++++++++++++++++++---------- 1 file changed, 23 insertions(+), 10 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/mesos/blob/e46e16a4/src/master/registrar.cpp ---------------------------------------------------------------------- diff --git a/src/master/registrar.cpp b/src/master/registrar.cpp index ccc2fd2..0831963 100644 --- a/src/master/registrar.cpp +++ b/src/master/registrar.cpp @@ -37,6 +37,7 @@ #include <stout/nothing.hpp> #include <stout/option.hpp> #include <stout/protobuf.hpp> +#include <stout/stopwatch.hpp> #include "common/type_utils.hpp" @@ -311,7 +312,8 @@ Future<Registry> RegistrarProcess::recover(const MasterInfo& info) if (recovered.isNone()) { LOG(INFO) << "Recovering registrar"; - metrics.state_fetch.time(state->fetch<Registry>("registry")) + metrics.state_fetch.start(); + state->fetch<Registry>("registry") .after(flags.registry_fetch_timeout, lambda::bind( &timeout<Variable<Registry> >, @@ -339,12 +341,15 @@ void RegistrarProcess::_recover( recovered.get()->fail("Failed to recover registrar: " + (recovery.isFailed() ? recovery.failure() : "discarded")); } else { + Duration elapsed = metrics.state_fetch.stop(); + + LOG(INFO) << "Successfully fetched the registry" + << " (" << Bytes(recovery.get().get().ByteSize()) << ")" + << " in " << elapsed; + // Save the registry. variable = recovery.get(); - LOG(INFO) << "Successfully fetched the registry " - << "(" << Bytes(variable.get().get().ByteSize()) << ")"; - // Perform the Recover operation to add the new MasterInfo. Owned<Operation> operation(new Recover(info)); operations.push_back(operation); @@ -415,12 +420,13 @@ void RegistrarProcess::update() CHECK(!updating); CHECK(error.isNone()); + CHECK_SOME(variable); - updating = true; - - LOG(INFO) << "Attempting to update the 'registry'"; + // Time how long it takes to apply the operations. + Stopwatch stopwatch; + stopwatch.start(); - CHECK_SOME(variable); + updating = true; // Create a snapshot of the current registry. Registry registry = variable.get().get(); @@ -436,8 +442,12 @@ void RegistrarProcess::update() (*operation)(®istry, &slaveIDs, flags.registry_strict); } + LOG(INFO) << "Applied " << operations.size() << " operations in " + << stopwatch.elapsed() << "; attempting to update the 'registry'"; + // Perform the store, and time the operation. - metrics.state_store.time(state->store(variable.get().mutate(registry))) + metrics.state_store.start(); + state->store(variable.get().mutate(registry)) .after(flags.registry_store_timeout, lambda::bind( &timeout<Option<Variable<Registry> > >, @@ -475,7 +485,10 @@ void RegistrarProcess::_update( return; } - LOG(INFO) << "Successfully updated 'registry'"; + Duration elapsed = metrics.state_store.stop(); + + LOG(INFO) << "Successfully updated the 'registry' in " << elapsed; + variable = store.get().get(); // Remove the operations.
