filestore: simplify, clean up perfcounters

Signed-off-by: Sage Weil <sage.weil@dreamhost.com>

diff --git a/src/os/FileJournal.cc b/src/os/FileJournal.cc
index 0d9d62a227257f40616307ec38edb21977eda855..c446f9c77dc0754483550c15906d7e68b7baf955 100644 (file)
--- a/src/os/FileJournal.cc
+++ b/src/os/FileJournal.cc
@@ -651,11 +651,20 @@ void FileJournal::queue_write_fin(uint64_t seq, Context *fin)
 
 void FileJournal::queue_completions_thru(uint64_t seq)
 {
+  utime_t now = ceph_clock_now(g_ceph_context);
   while (!completions.empty() &&
-        completions.front().first <= seq) {
-    dout(10) << "queue_completions_thru seq " << seq << " queueing seq " << completions.front().first
-            << " " << completions.front().second << dendl;
-    finisher->queue(completions.front().second);
+        completions.front().seq <= seq) {
+    utime_t lat = now;
+    lat -= completions.front().start;
+    dout(10) << "queue_completions_thru seq " << seq
+            << " queueing seq " << completions.front().seq
+            << " " << completions.front().finish
+            << " lat " << lat << dendl;
+    if (logger) {
+      logger->finc(l_os_j_lat, lat);
+    }
+    if (completions.front().finish)
+      finisher->queue(completions.front().finish);
     completions.pop_front();
   }
 }
@@ -932,8 +941,7 @@ void FileJournal::submit_entry(uint64_t seq, bufferlist& e, int alignment, Conte
           << " len " << e.length()
           << " (" << oncommit << ")" << dendl;
 
-  if (oncommit)
-    completions.push_back(pair<uint64_t,Context*>(seq, oncommit));
+  completions.push_back(completion_item(seq, oncommit, ceph_clock_now(g_ceph_context)));
 
   if (full_state == FULL_NOTFULL) {
     // queue and kick writer thread

diff --git a/src/os/FileJournal.h b/src/os/FileJournal.h
index d2a9a72be398a49b271ad73bd300ace85bddd9a1..f4e7801f6587c6c896e5f0646d68ada709867235 100644 (file)
--- a/src/os/FileJournal.h
+++ b/src/os/FileJournal.h
@@ -98,7 +98,15 @@ private:
 
   // in journal
   deque<pair<uint64_t, off64_t> > journalq;  // track seq offsets, so we can trim later.
-  deque<pair<uint64_t,Context*> > completions;  // queued, writing, waiting for commit.
+
+  struct completion_item {
+    uint64_t seq;
+    Context *finish;
+    utime_t start;
+    completion_item(uint64_t o, Context *c, utime_t s)
+      : seq(o), finish(c), start(s) {}
+  };
+  deque<completion_item> completions;  // queued, writing, waiting for commit.
 
   uint64_t writing_seq, journaled_seq;
   bool plug_journal_completions;

diff --git a/src/os/FileStore.cc b/src/os/FileStore.cc
index 7ba1304e614dd983ee0b4116da38177a70640d88..c7d4b548e21b1e3d7f5f96ffc6f416f12cf40166 100644 (file)
--- a/src/os/FileStore.cc
+++ b/src/os/FileStore.cc
@@ -669,25 +669,20 @@ FileStore::FileStore(const std::string &base, const std::string &jdev) :
   // initialize logger
   PerfCountersBuilder plb(g_ceph_context, "filestore", l_os_first, l_os_last);
 
-  plb.add_u64_counter(l_os_in_ops, "in_ops");
-  plb.add_u64_counter(l_os_in_bytes, "in_bytes");
-  plb.add_u64_counter(l_os_readable_ops, "readable_ops");
-  plb.add_u64_counter(l_os_readable_bytes, "readable_bytes");
-  plb.add_u64_counter(l_os_commit_ops, "commit_ops");
-  plb.add_u64_counter(l_os_commit_bytes, "commit_bytes");
-
   plb.add_u64(l_os_jq_max_ops, "journal_queue_max_ops");
   plb.add_u64(l_os_jq_ops, "journal_queue_ops");
   plb.add_u64_counter(l_os_j_ops, "journal_ops");
   plb.add_u64(l_os_jq_max_bytes, "journal_queue_max_bytes");
   plb.add_u64(l_os_jq_bytes, "journal_queue_bytes");
   plb.add_u64_counter(l_os_j_bytes, "journal_bytes");
+  plb.add_fl_avg(l_os_j_lat, "journal_latency");
   plb.add_u64(l_os_oq_max_ops, "op_queue_max_ops");
   plb.add_u64(l_os_oq_ops, "op_queue_ops");
   plb.add_u64_counter(l_os_ops, "ops");
   plb.add_u64(l_os_oq_max_bytes, "op_queue_max_bytes");
   plb.add_u64(l_os_oq_bytes, "op_queue_bytes");
   plb.add_u64_counter(l_os_bytes, "bytes");
+  plb.add_fl_avg(l_os_apply_lat, "apply_latency");
   plb.add_u64(l_os_committing, "committing");
 
   logger = plb.create_perf_counters();
@@ -1814,6 +1809,7 @@ FileStore::Op *FileStore::build_op(list<Transaction*>& tls,
   }
 
   Op *o = new Op;
+  o->start = ceph_clock_now(g_ceph_context);
   o->tls.swap(tls);
   o->onreadable = onreadable;
   o->onreadable_sync = onreadable_sync;
@@ -1920,8 +1916,9 @@ void FileStore::_finish_op(OpSequencer *osr)
   // called with tp lock held
   _op_queue_release_throttle(o);
 
-  logger->inc(l_os_readable_ops);
-  logger->inc(l_os_readable_bytes, o->bytes);
+  utime_t lat = ceph_clock_now(g_ceph_context);
+  lat -= o->start;
+  logger->finc(l_os_apply_lat, lat);
 
   if (next_finish == o->op) {
     dout(10) << "_finish_op " << o->op << " next_finish " << next_finish
@@ -1994,9 +1991,6 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
     dout(5) << "queue_transactions new osr " << osr << "/" << osr->parent << dendl;
   }
 
-  logger->inc(l_os_in_ops);
-  //logger->inc(l_os_in_bytes, 1); 
-
   if (journal && journal->is_writeable() && !m_filestore_journal_trailing) {
     Op *o = build_op(tls, onreadable, onreadable_sync);
     op_queue_reserve_throttle(o);
@@ -2045,9 +2039,6 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
   op_submit_finish(op);
   op_apply_finish(op);
 
-  logger->inc(l_os_readable_ops);
-  //fixme logger->inc(l_os_readable_bytes, 1);
-
   return r;
 }
 

diff --git a/src/os/FileStore.h b/src/os/FileStore.h
index 0840970a1e9fc6fd91a5e5221329c24b4b71b784..bf7c35d8f034fc81ab4afb899997829dd90b9c98 100644 (file)
--- a/src/os/FileStore.h
+++ b/src/os/FileStore.h
@@ -106,6 +106,7 @@ class FileStore : public JournalingObjectStore,
 
   // -- op workqueue --
   struct Op {
+    utime_t start;
     uint64_t op;
     list<Transaction*> tls;
     Context *onreadable, *onreadable_sync;

diff --git a/src/os/ObjectStore.h b/src/os/ObjectStore.h
index adf8843a3fb228a7eef93ca662c86fdd5f9fa619..cb2053814a051807f3b4f19a8af96dbc99c63e63 100644 (file)
--- a/src/os/ObjectStore.h
+++ b/src/os/ObjectStore.h
@@ -42,24 +42,20 @@ class Logger;
 
 enum {
   l_os_first = 84000,
-  l_os_in_ops,
-  l_os_in_bytes,
-  l_os_readable_ops,
-  l_os_readable_bytes,
-  l_os_commit_ops,
-  l_os_commit_bytes,
   l_os_jq_max_ops,
   l_os_jq_ops,
   l_os_j_ops,
   l_os_jq_max_bytes,
   l_os_jq_bytes,
   l_os_j_bytes,
+  l_os_j_lat,
   l_os_oq_max_ops,
   l_os_oq_ops,
   l_os_ops,
   l_os_oq_max_bytes,
   l_os_oq_bytes,
   l_os_bytes,
+  l_os_apply_lat,
   l_os_committing,
   l_os_last,
 };