From: Sage Weil Date: Thu, 20 Oct 2011 19:43:20 +0000 (-0700) Subject: filestore: simplify, clean up perfcounters X-Git-Tag: v0.38~57^2~30^2~7 X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=b000e4d4aed9e59189e3b1360ee2415db1298bf4;p=ceph.git filestore: simplify, clean up perfcounters Signed-off-by: Sage Weil --- diff --git a/src/os/FileJournal.cc b/src/os/FileJournal.cc index 0d9d62a227257..c446f9c77dc07 100644 --- 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(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 d2a9a72be398a..f4e7801f6587c 100644 --- a/src/os/FileJournal.h +++ b/src/os/FileJournal.h @@ -98,7 +98,15 @@ private: // in journal deque > journalq; // track seq offsets, so we can trim later. - deque > 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 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 7ba1304e614dd..c7d4b548e21b1 100644 --- 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& 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 &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 &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 0840970a1e9fc..bf7c35d8f034f 100644 --- 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 tls; Context *onreadable, *onreadable_sync; diff --git a/src/os/ObjectStore.h b/src/os/ObjectStore.h index adf8843a3fb22..cb2053814a051 100644 --- 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, };