mon: use mono clock for duration

Signed-off-by: Patrick Donnelly <pdonnell@redhat.com>

diff --git a/src/common/ceph_time.h b/src/common/ceph_time.h
index 49707e98c3ac1d8495110685d9f82aea72456de6..afe8aead7cee1a0e2865daa49359dd0de48bb87d 100644 (file)
--- a/src/common/ceph_time.h
+++ b/src/common/ceph_time.h
@@ -17,6 +17,7 @@
 
 #include <chrono>
 
+#include "include/assert.h"
 #include "include/encoding.h"
 
 #if defined(__APPLE__)
@@ -499,6 +500,10 @@ namespace std {
        std::chrono::duration_cast<timespan>(z) :
        timespan(-z.count());
     }
+    inline timespan to_timespan(signedspan z) {
+      ceph_assert(z >= signedspan::zero());
+      return std::chrono::duration_cast<timespan>(z);
+    }
   }
 } // namespace std
 

diff --git a/src/mon/Monitor.cc b/src/mon/Monitor.cc
index ca737a87451e0491a280adef0990d011a2550f55..92031072943794d25c45f89be864d13ebec32372 100644 (file)
--- a/src/mon/Monitor.cc
+++ b/src/mon/Monitor.cc
@@ -3104,13 +3104,13 @@ void Monitor::handle_command(MonOpRequestRef op)
 
   if (prefix == "compact" || prefix == "mon compact") {
     dout(1) << "triggering manual compaction" << dendl;
-    utime_t start = ceph_clock_now();
+    auto start = ceph::coarse_mono_clock::now();
     store->compact();
-    utime_t end = ceph_clock_now();
-    end -= start;
-    dout(1) << "finished manual compaction in " << end << " seconds" << dendl;
+    auto end = ceph::coarse_mono_clock::now();
+    double duration = std::chrono::duration<double>(end-start).count();
+    dout(1) << "finished manual compaction in " << duration << " seconds" << dendl;
     ostringstream oss;
-    oss << "compacted " << g_conf->get_val<std::string>("mon_keyvaluedb") << " in " << end << " seconds";
+    oss << "compacted " << g_conf->get_val<std::string>("mon_keyvaluedb") << " in " << duration << " seconds";
     rs = oss.str();
     r = 0;
   }

diff --git a/src/mon/Paxos.cc b/src/mon/Paxos.cc
index e92438769f088a910be5e7c6097e8a19e31caad3..d3c13861d60a4da6488fa075634ead5cc8e4342e 100644 (file)
--- a/src/mon/Paxos.cc
+++ b/src/mon/Paxos.cc
@@ -266,12 +266,12 @@ void Paxos::handle_collect(MonOpRequestRef op)
     logger->inc(l_paxos_collect);
     logger->inc(l_paxos_collect_keys, t->get_keys());
     logger->inc(l_paxos_collect_bytes, t->get_bytes());
-    utime_t start = ceph_clock_now();
 
+    auto start = ceph::coarse_mono_clock::now();
     get_store()->apply_transaction(t);
+    auto end = ceph::coarse_mono_clock::now();
 
-    utime_t end = ceph_clock_now();
-    logger->tinc(l_paxos_collect_latency, end - start);
+    logger->tinc(l_paxos_collect_latency, to_timespan(end - start));
   } else {
     // don't accept!
     dout(10) << "NOT accepting pn " << collect->pn << " from " << collect->pn_from
@@ -433,12 +433,12 @@ bool Paxos::store_state(MMonPaxos *m)
     logger->inc(l_paxos_store_state);
     logger->inc(l_paxos_store_state_bytes, t->get_bytes());
     logger->inc(l_paxos_store_state_keys, t->get_keys());
-    utime_t start = ceph_clock_now();
 
+    auto start = ceph::coarse_mono_clock::now();
     get_store()->apply_transaction(t);
+    auto end = ceph::coarse_mono_clock::now();
 
-    utime_t end = ceph_clock_now();
-    logger->tinc(l_paxos_store_state_latency, end - start);
+    logger->tinc(l_paxos_store_state_latency, to_timespan(end-start));
 
     // refresh first_committed; this txn may have trimmed.
     first_committed = get_store()->get(get_name(), "first_committed");
@@ -660,12 +660,12 @@ void Paxos::begin(bufferlist& v)
   logger->inc(l_paxos_begin);
   logger->inc(l_paxos_begin_keys, t->get_keys());
   logger->inc(l_paxos_begin_bytes, t->get_bytes());
-  utime_t start = ceph_clock_now();
 
+  auto start = ceph::coarse_mono_clock::now();
   get_store()->apply_transaction(t);
+  auto end = ceph::coarse_mono_clock::now();
 
-  utime_t end = ceph_clock_now();
-  logger->tinc(l_paxos_begin_latency, end - start);
+  logger->tinc(l_paxos_begin_latency, to_timespan(end - start));
 
   assert(g_conf->paxos_kill_at != 3);
 
@@ -744,12 +744,12 @@ void Paxos::handle_begin(MonOpRequestRef op)
   *_dout << dendl;
 
   logger->inc(l_paxos_begin_bytes, t->get_bytes());
-  utime_t start = ceph_clock_now();
 
+  auto start = ceph::coarse_mono_clock::now();
   get_store()->apply_transaction(t);
+  auto end = ceph::coarse_mono_clock::now();
 
-  utime_t end = ceph_clock_now();
-  logger->tinc(l_paxos_begin_latency, end - start);
+  logger->tinc(l_paxos_begin_latency, to_timespan(end - start));
 
   assert(g_conf->paxos_kill_at != 5);
 
@@ -1040,14 +1040,13 @@ bool Paxos::do_refresh()
 {
   bool need_bootstrap = false;
 
-  utime_t start = ceph_clock_now();
-
   // make sure we have the latest state loaded up
+  auto start = ceph::coarse_mono_clock::now();
   mon->refresh_from_paxos(&need_bootstrap);
+  auto end = ceph::coarse_mono_clock::now();
 
-  utime_t end = ceph_clock_now();
   logger->inc(l_paxos_refresh);
-  logger->tinc(l_paxos_refresh_latency, end - start);
+  logger->tinc(l_paxos_refresh_latency, to_timespan(end - start));
 
   if (need_bootstrap) {
     dout(10) << " doing requested bootstrap" << dendl;
@@ -1278,12 +1277,12 @@ version_t Paxos::get_new_proposal_number(version_t gt)
   *_dout << dendl;
 
   logger->inc(l_paxos_new_pn);
-  utime_t start = ceph_clock_now();
 
+  auto start = ceph::coarse_mono_clock::now();
   get_store()->apply_transaction(t);
+  auto end = ceph::coarse_mono_clock::now();
 
-  utime_t end = ceph_clock_now();
-  logger->tinc(l_paxos_new_pn_latency, end - start);
+  logger->tinc(l_paxos_new_pn_latency, to_timespan(end - start));
 
   dout(10) << "get_new_proposal_number = " << last_pn << dendl;
   return last_pn;

diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc
index 188175ccc0653ac513a4c6c89fc7e9a1744ba602..88cfd7a1b1b369bcd585bacc00fafd74cb7c5bdb 100644 (file)
--- a/src/osd/OSD.cc
+++ b/src/osd/OSD.cc
@@ -2285,12 +2285,12 @@ will start to track new ops received afterwards.";
     auto start = ceph::coarse_mono_clock::now();
     store->compact();
     auto end = ceph::coarse_mono_clock::now();
-    auto time_span = chrono::duration_cast<chrono::duration<double>>(end - start);
+    double duration = std::chrono::duration<double>(end-start).count();
     dout(1) << "finished manual compaction in " 
-            << time_span.count()
+            << duration
             << " seconds" << dendl;
     f->open_object_section("compact_result");
-    f->dump_float("elapsed_time", time_span.count());
+    f->dump_float("elapsed_time", duration);
     f->close_section();
   } else {
     assert(0 == "broken asok registration");
@@ -6403,11 +6403,11 @@ void OSD::do_command(Connection *con, ceph_tid_t tid, vector<string>& cmd, buffe
     auto start = ceph::coarse_mono_clock::now();
     store->compact();
     auto end = ceph::coarse_mono_clock::now();
-    auto time_span = chrono::duration_cast<chrono::duration<double>>(end - start);
+    double duration = std::chrono::duration<double>(end-start).count();
     dout(1) << "finished manual compaction in "
-            << time_span.count()
+            << duration
             << " seconds" << dendl;
-    ss << "compacted omap in " << time_span.count() << " seconds";
+    ss << "compacted omap in " << duration << " seconds";
   }
 
   else {