diff --git a/src/yb/tablet/write_query.cc b/src/yb/tablet/write_query.cc index 37a107b3855e..1fb070844312 100644 --- a/src/yb/tablet/write_query.cc +++ b/src/yb/tablet/write_query.cc @@ -197,7 +197,7 @@ WriteQuery::WriteQuery( context_(context), rpc_context_(rpc_context), response_(response), - start_time_(CoarseMonoClock::Now()), + start_time_(MonoTime::Now()), execute_mode_(ExecuteMode::kSimple) { IncrementActiveWriteQueryObjectsBy(1); } @@ -308,7 +308,8 @@ void WriteQuery::Finished(WriteOperation* operation, const Status& status) { TabletMetrics* metrics = tablet->metrics(); if (metrics) { auto op_duration_usec = - make_unsigned(MonoDelta(CoarseMonoClock::now() - start_time_).ToMicroseconds()); + make_unsigned(MonoDelta(MonoTime::Now() - start_time_).ToMicroseconds()); + metrics->Increment(tablet::TabletEventStats::kQlWriteLatency, op_duration_usec); } } diff --git a/src/yb/tablet/write_query.h b/src/yb/tablet/write_query.h index d3eec5265634..fd12b68e2ef7 100644 --- a/src/yb/tablet/write_query.h +++ b/src/yb/tablet/write_query.h @@ -218,7 +218,7 @@ class WriteQuery { tserver::WriteResponsePB* response_; // this transaction's start time - CoarseTimePoint start_time_; + MonoTime start_time_; HybridTime restart_read_ht_; diff --git a/src/yb/util/monotime-test.cc b/src/yb/util/monotime-test.cc index 2e3f09632f8a..c00d3f5a5170 100644 --- a/src/yb/util/monotime-test.cc +++ b/src/yb/util/monotime-test.cc @@ -36,6 +36,7 @@ #include "yb/util/logging.h" #include +#include "yb/util/test_thread_holder.h" #include "yb/util/test_util.h" using namespace std::literals; @@ -299,4 +300,38 @@ TEST(TestMonoTime, ToStringRelativeToNow) { ASSERT_EQ(ToString(t), ToStringRelativeToNow(t, CoarseTimePoint::max())); } +// Make sure the MonoTime::Now() value does not move backwards. +// Run multiple threads to increase the chance of catching the issue. +// Run for 30 seconds. +TEST(TestMonoTime, DontMoveBackwards) { + // Make sure we are using a steady clock for MonoTime. + ASSERT_TRUE(std::chrono::steady_clock::is_steady); + + LOG(WARNING) << "Now: " << MonoTime::Now().ToSteadyTimePoint().time_since_epoch().count(); + + std::atomic stop_flag{false}; + + auto t = [&stop_flag]() { + auto old = MonoTime::Now(); + while (!stop_flag.load(std::memory_order_acquire)) { + auto now = MonoTime::Now(); + ASSERT_GE(now, old) << "Time moved back!! " + << " Old:" << old.ToSteadyTimePoint().time_since_epoch().count() + << ", Now:" << old.ToSteadyTimePoint().time_since_epoch().count(); + old = now; + } + }; + + TestThreadHolder holder; + holder.AddThreadFunctor(t); + holder.AddThreadFunctor(t); + holder.AddThreadFunctor(t); + holder.AddThreadFunctor(t); + + SleepFor(MonoDelta::FromSeconds(30)); + stop_flag.store(true, std::memory_order_release); + + holder.JoinAll(); +} + } // namespace yb