os/bluestore: fix a bug: when using bluestore, the output of

"ceph osd perf" is always 0ms.

Signed-off-by: Pan Liu <pan.liu@istuary.com>

diff --git a/src/os/bluestore/BlueStore.cc b/src/os/bluestore/BlueStore.cc
index b27e3c51bfc8ee42cc3aae96a063436618d3294d..c44d6afba1b2cfead0f356543d3f0d1a9603fa6f 100644 (file)
--- a/src/os/bluestore/BlueStore.cc
+++ b/src/os/bluestore/BlueStore.cc
@@ -2640,6 +2640,8 @@ void BlueStore::_init_logger()
     "Average finishing state latency");
   b.add_time_avg(l_bluestore_state_done_lat, "state_done_lat",
     "Average done state latency");
+  b.add_time_avg(l_bluestore_commit_lat, "commit_lat",
+    "Average commit latency");
   b.add_time_avg(l_bluestore_compress_lat, "compress_lat",
     "Average compress latency");
   b.add_time_avg(l_bluestore_decompress_lat, "decompress_lat",
@@ -6427,6 +6429,7 @@ void BlueStore::_txc_finish_kv(TransContext *txc)
   }
   unsigned n = txc->osr->parent->shard_hint.hash_to_shard(m_finisher_num);
   if (txc->oncommit) {
+    logger->tinc(l_bluestore_commit_lat, ceph_clock_now(g_ceph_context) - txc->start);
     finishers[n]->queue(txc->oncommit);
     txc->oncommit = NULL;
   }
@@ -6444,6 +6447,17 @@ void BlueStore::_txc_finish_kv(TransContext *txc)
   throttle_bytes.put(txc->bytes);
 }
 
+void BlueStore::BSPerfTracker::update_from_perfcounters(
+  PerfCounters &logger)
+{
+  os_commit_latency.consume_next(
+    logger.get_tavg_ms(
+      l_bluestore_commit_lat));
+  os_apply_latency.consume_next(
+    logger.get_tavg_ms(
+      l_bluestore_commit_lat));
+}
+
 void BlueStore::_txc_finish(TransContext *txc)
 {
   dout(20) << __func__ << " " << txc << " onodes " << txc->onodes << dendl;

diff --git a/src/os/bluestore/BlueStore.h b/src/os/bluestore/BlueStore.h
index 5db44e6a39f8c364a53895bb14b12046059aa3b6..877d10d0b28e6f1fd3f4f100803eef74326803a3 100644 (file)
--- a/src/os/bluestore/BlueStore.h
+++ b/src/os/bluestore/BlueStore.h
@@ -59,6 +59,7 @@ enum {
   l_bluestore_state_wal_cleanup_lat,
   l_bluestore_state_finishing_lat,
   l_bluestore_state_done_lat,
+  l_bluestore_commit_lat,
   l_bluestore_compress_lat,
   l_bluestore_decompress_lat,
   l_bluestore_csum_lat,
@@ -1203,9 +1204,10 @@ public:
 
     void log_state_latency(PerfCounters *logger, int state) {
       utime_t lat, now = ceph_clock_now(g_ceph_context);
-      lat = now - start;
+      lat = now - last_stamp;
       logger->tinc(state, lat);
       start = now;
+      last_stamp = now;
     }
 
     OpSequencerRef osr;
@@ -1288,6 +1290,7 @@ public:
 
     uint64_t seq = 0;
     utime_t start;
+    utime_t last_stamp;
 
     uint64_t last_nid = 0;     ///< if non-zero, highest new nid we allocated
     uint64_t last_blobid = 0;  ///< if non-zero, highest new blobid we allocated
@@ -1303,6 +1306,7 @@ public:
        wal_txn(NULL),
        ioc(this),
        start(ceph_clock_now(g_ceph_context)) {
+        last_stamp = start;
     }
     ~TransContext() {
       delete wal_txn;
@@ -1904,8 +1908,23 @@ public:
     return num_objects * 300; //assuming per-object overhead is 300 bytes
   }
 
+  struct BSPerfTracker {
+    PerfCounters::avg_tracker<uint64_t> os_commit_latency;
+    PerfCounters::avg_tracker<uint64_t> os_apply_latency;
+
+    objectstore_perf_stat_t get_cur_stats() const {
+      objectstore_perf_stat_t ret;
+      ret.os_commit_latency = os_commit_latency.avg();
+      ret.os_apply_latency = os_apply_latency.avg();
+      return ret;
+    }
+
+    void update_from_perfcounters(PerfCounters &logger);
+  } perf_tracker;
+
   objectstore_perf_stat_t get_cur_stats() override {
-    return objectstore_perf_stat_t();
+    perf_tracker.update_from_perfcounters(*logger);
+    return perf_tracker.get_cur_stats();
   }
 
   int queue_transactions(