From c7f55c40ab6be5fd32546e0f6cd946a89ed8c36f Mon Sep 17 00:00:00 2001 From: Pan Liu Date: Fri, 18 Nov 2016 16:26:19 +0800 Subject: [PATCH] os/bluestore: fix a bug: when using bluestore, the output of "ceph osd perf" is always 0ms. Signed-off-by: Pan Liu --- src/os/bluestore/BlueStore.cc | 14 ++++++++++++++ src/os/bluestore/BlueStore.h | 23 +++++++++++++++++++++-- 2 files changed, 35 insertions(+), 2 deletions(-) diff --git a/src/os/bluestore/BlueStore.cc b/src/os/bluestore/BlueStore.cc index b27e3c51bfc..c44d6afba1b 100644 --- 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 5db44e6a39f..877d10d0b28 100644 --- 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 os_commit_latency; + PerfCounters::avg_tracker 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( -- 2.39.5