From: Igor Fedotov <ifedotov@mirantis.com>
Date: Mon, 6 Feb 2017 12:36:43 +0000 (+0000)
Subject: os/bluestore: add more perf_counters to BlueStore
X-Git-Tag: v12.0.1~426^2
X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=cc79d48c97e11ba173401d46f7d4f2b6e5743837;p=ceph.git

os/bluestore: add more perf_counters to BlueStore

Signed-off-by: Igor Fedotov <ifedotov@mirantis.com>
---

diff --git a/src/os/bluestore/BlueStore.cc b/src/os/bluestore/BlueStore.cc
index d7a3e118b5f5..a8bcaa3624f5 100644
--- a/src/os/bluestore/BlueStore.cc
+++ b/src/os/bluestore/BlueStore.cc
@@ -2273,6 +2273,9 @@ void BlueStore::ExtentMap::fault_range(
 	       << std::dec << " (" << v.length() << " bytes)" << dendl;
       assert(p->dirty == false);
       assert(v.length() == p->shard_info->bytes);
+      onode->c->store->logger->inc(l_bluestore_onode_shard_misses);
+    } else {
+      onode->c->store->logger->inc(l_bluestore_onode_shard_hits);
     }
     ++start;
   }
@@ -2990,6 +2993,14 @@ void BlueStore::_init_logger()
     "Average submit latency");
   b.add_time_avg(l_bluestore_commit_lat, "commit_lat",
     "Average commit latency");
+  b.add_time_avg(l_bluestore_read_lat, "read_lat",
+    "Average read latency");
+  b.add_time_avg(l_bluestore_read_onode_meta_lat, "read_onode_meta_lat",
+    "Average read onode metadata latency");
+  b.add_time_avg(l_bluestore_read_wait_flush_lat, "read_wait_flush_lat",
+    "Average wait flush latency during reads");
+  b.add_time_avg(l_bluestore_read_wait_aio_lat, "read_wait_aio_lat",
+    "Average read latency");
   b.add_time_avg(l_bluestore_compress_lat, "compress_lat",
     "Average compress latency");
   b.add_time_avg(l_bluestore_decompress_lat, "decompress_lat",
@@ -3025,6 +3036,10 @@ void BlueStore::_init_logger()
     "Sum for onode-lookups hit in the cache");
   b.add_u64(l_bluestore_onode_misses, "bluestore_onode_misses",
     "Sum for onode-lookups missed in the cache");
+  b.add_u64(l_bluestore_onode_shard_hits, "bluestore_onode_shard_hits",
+    "Sum for onode-shard lookups hit in the cache");
+  b.add_u64(l_bluestore_onode_shard_misses, "bluestore_onode_shard_misses",
+    "Sum for onode-shard lookups missed in the cache");
   b.add_u64(l_bluestore_extents, "bluestore_extents",
 	    "Number of extents in cache");
   b.add_u64(l_bluestore_blobs, "bluestore_blobs",
@@ -5266,6 +5281,7 @@ int BlueStore::read(
   uint32_t op_flags,
   bool allow_eio)
 {
+  utime_t start = ceph_clock_now();
   Collection *c = static_cast<Collection *>(c_.get());
   const coll_t &cid = c->get_cid();
   dout(15) << __func__ << " " << cid << " " << oid
@@ -5278,8 +5294,9 @@ int BlueStore::read(
   int r;
   {
     RWLock::RLocker l(c->lock);
-
+    utime_t start1 = ceph_clock_now();
     OnodeRef o = c->get_onode(oid, false);
+    logger->tinc(l_bluestore_read_onode_meta_lat, ceph_clock_now() - start1);
     if (!o || !o->exists) {
       r = -ENOENT;
       goto out;
@@ -5301,6 +5318,7 @@ int BlueStore::read(
   dout(10) << __func__ << " " << cid << " " << oid
 	   << " 0x" << std::hex << offset << "~" << length << std::dec
 	   << " = " << r << dendl;
+  logger->tinc(l_bluestore_read_lat, ceph_clock_now() - start);
   return r;
 }
 
@@ -5372,9 +5390,13 @@ int BlueStore::_do_read(
     length = o->onode.size - offset;
   }
 
+  utime_t start = ceph_clock_now();
   o->flush();
+  logger->tinc(l_bluestore_read_wait_flush_lat, ceph_clock_now() - start);
 
+  start = ceph_clock_now();
   o->extent_map.fault_range(db, offset, length);
+  logger->tinc(l_bluestore_read_onode_meta_lat, ceph_clock_now() - start);
   _dump_onode(o);
 
   ready_regions_t ready_regions;
@@ -5440,6 +5462,9 @@ int BlueStore::_do_read(
   }
 
   // read raw blob data.  use aio if we have >1 blobs to read.
+  start = ceph_clock_now(); // for the sake of simplicity 
+                                    // measure the whole block below.
+                                    // The error isn't that much...
   vector<bufferlist> compressed_blob_bls;
   IOContext ioc(cct, NULL);
   for (auto& p : blobs2read) {
@@ -5516,6 +5541,7 @@ int BlueStore::_do_read(
     dout(20) << __func__ << " waiting for aio" << dendl;
     ioc.aio_wait();
   }
+  logger->tinc(l_bluestore_read_wait_aio_lat, ceph_clock_now() - start);
 
   // enumerate and decompress desired blobs
   auto p = compressed_blob_bls.begin();
diff --git a/src/os/bluestore/BlueStore.h b/src/os/bluestore/BlueStore.h
index 160a96f27548..5e9ce34d5724 100644
--- a/src/os/bluestore/BlueStore.h
+++ b/src/os/bluestore/BlueStore.h
@@ -64,6 +64,10 @@ enum {
   l_bluestore_state_done_lat,
   l_bluestore_submit_lat,
   l_bluestore_commit_lat,
+  l_bluestore_read_lat,
+  l_bluestore_read_onode_meta_lat,
+  l_bluestore_read_wait_flush_lat,
+  l_bluestore_read_wait_aio_lat,
   l_bluestore_compress_lat,
   l_bluestore_decompress_lat,
   l_bluestore_csum_lat,
@@ -81,6 +85,8 @@ enum {
   l_bluestore_onodes,
   l_bluestore_onode_hits,
   l_bluestore_onode_misses,
+  l_bluestore_onode_shard_hits,
+  l_bluestore_onode_shard_misses,
   l_bluestore_extents,
   l_bluestore_blobs,
   l_bluestore_buffers,