PerfCounter: Make l_os_queue_lat contains the complete queue latency

We don't need l_os_queue_lat to only count the latency of op throttle, this
could be done by Throttle counter itself. We may concern the latency consumed
by FileJournal submit time.

Signed-off-by: Haomai Wang <haomaiwang@gmail.com>

diff --git a/src/os/FileStore.cc b/src/os/FileStore.cc
index 5f175444619372dcfce06ebe3732a1540b53a9da..736bccf6accc4d9035558fb40ba05559aed5903e 100644 (file)
--- a/src/os/FileStore.cc
+++ b/src/os/FileStore.cc
@@ -1820,7 +1820,6 @@ void FileStore::op_queue_reserve_throttle(Op *o, ThreadPool::TPHandle *handle)
   logger->set(l_os_oq_max_ops, max_ops);
   logger->set(l_os_oq_max_bytes, max_bytes);
 
-  utime_t start = ceph_clock_now(g_ceph_context);
   if (handle)
     handle->suspend_tp_timeout();
   if (throttle_ops.should_wait(1) || 
@@ -1834,9 +1833,6 @@ void FileStore::op_queue_reserve_throttle(Op *o, ThreadPool::TPHandle *handle)
   if (handle)
     handle->reset_tp_timeout();
 
-  utime_t end = ceph_clock_now(g_ceph_context);
-  logger->tinc(l_os_queue_lat, end - start);
-
   logger->set(l_os_oq_ops, throttle_ops.get_current());
   logger->set(l_os_oq_bytes, throttle_bytes.get_current());
 }
@@ -1931,6 +1927,7 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
     return 0;
   }
 
+  utime_t start = ceph_clock_now(g_ceph_context);
   // set up the sequencer
   OpSequencer *osr;
   if (!posr)
@@ -1982,6 +1979,8 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
       assert(0);
     }
     submit_manager.op_submit_finish(op_num);
+    utime_t end = ceph_clock_now(g_ceph_context);
+    logger->tinc(l_os_queue_lat, end - start);
     return 0;
   }
 
@@ -2002,6 +2001,8 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
     if (ondisk)
       apply_manager.add_waiter(op_num, ondisk);
     submit_manager.op_submit_finish(op_num);
+    utime_t end = ceph_clock_now(g_ceph_context);
+    logger->tinc(l_os_queue_lat, end - start);
     return 0;
   }
 
@@ -2034,6 +2035,8 @@ int FileStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
   submit_manager.op_submit_finish(op);
   apply_manager.op_apply_finish(op);
 
+  utime_t end = ceph_clock_now(g_ceph_context);
+  logger->tinc(l_os_queue_lat, end - start);
   return r;
 }
 

diff --git a/src/os/KeyValueStore.cc b/src/os/KeyValueStore.cc
index a147c0b27ab428bca814f28a70510cde61976b92..2e4036adc60461196f617949854184d113d928f3 100644 (file)
--- a/src/os/KeyValueStore.cc
+++ b/src/os/KeyValueStore.cc
@@ -1041,6 +1041,7 @@ int KeyValueStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
                                       TrackedOpRef osd_op,
                                       ThreadPool::TPHandle *handle)
 {
+  utime_t start = ceph_clock_now(g_ceph_context);
   Context *onreadable;
   Context *ondisk;
   Context *onreadable_sync;
@@ -1069,6 +1070,8 @@ int KeyValueStore::queue_transactions(Sequencer *posr, list<Transaction*> &tls,
   dout(5) << "queue_transactions (trailing journal) " << " " << tls <<dendl;
   queue_op(osr, o);
 
+  utime_t end = ceph_clock_now(g_ceph_context);
+  perf_logger->tinc(l_os_queue_lat, end - start);
   return 0;
 }
 
@@ -1124,7 +1127,6 @@ void KeyValueStore::op_queue_reserve_throttle(Op *o, ThreadPool::TPHandle *handl
   perf_logger->set(l_os_oq_max_ops, max_ops);
   perf_logger->set(l_os_oq_max_bytes, max_bytes);
 
-  utime_t start = ceph_clock_now(g_ceph_context);
   if (handle)
     handle->suspend_tp_timeout();
   if (throttle_ops.should_wait(1) ||
@@ -1138,9 +1140,6 @@ void KeyValueStore::op_queue_reserve_throttle(Op *o, ThreadPool::TPHandle *handl
   if (handle)
     handle->reset_tp_timeout();
 
-  utime_t end = ceph_clock_now(g_ceph_context);
-  perf_logger->tinc(l_os_queue_lat, end - start);
-
   perf_logger->set(l_os_oq_ops, throttle_ops.get_current());
   perf_logger->set(l_os_oq_bytes, throttle_bytes.get_current());
 }