From 61dd86d97e0883d1bea95ede26d2be8de80e4a2b Mon Sep 17 00:00:00 2001 From: Sage Weil Date: Thu, 26 Feb 2009 11:25:37 -0800 Subject: [PATCH] logger: identify fields with int constants instead of strings This avoids the crufty hashes and so forth. The only downside is that _all_ fields must be predeclared. That's probably a good thing anyway. Logger will assert if the key is invalid or the name hasn't been registered. Hopefully I haven't missed any. --- src/client/Client.cc | 55 +++---------- src/client/Client.h | 9 ++ src/client/SyntheticClient.cc | 12 +-- src/common/LogType.h | 113 +++++++------------------- src/common/Logger.cc | 149 +++++++++++++--------------------- src/common/Logger.h | 41 +++++----- src/dumpjournal.cc | 2 +- src/mds/CDir.cc | 8 +- src/mds/MDCache.cc | 44 +++++----- src/mds/MDLog.cc | 85 +++++++++---------- src/mds/MDLog.h | 21 +++++ src/mds/MDS.cc | 79 +++++++++--------- src/mds/MDS.h | 44 ++++++++++ src/mds/Migrator.cc | 8 +- src/mds/Server.cc | 20 ++--- src/mds/Server.h | 10 ++- src/osd/OSD.cc | 109 ++++++++++++------------- src/osd/OSD.h | 38 +++++++++ src/osd/ReplicatedPG.cc | 32 ++++---- src/osdc/Journaler.cc | 2 +- src/osdc/Journaler.h | 5 +- 21 files changed, 436 insertions(+), 450 deletions(-) diff --git a/src/client/Client.cc b/src/client/Client.cc index 11ad9ca0fb618..068d81af828f2 100644 --- a/src/client/Client.cc +++ b/src/client/Client.cc @@ -75,7 +75,7 @@ using namespace std; // static logger Mutex client_logger_lock("client_logger_lock"); -LogType client_logtype; +LogType client_logtype(l_c_first, l_c_last); Logger *client_logger = 0; @@ -251,26 +251,11 @@ void Client::init() // logger? client_logger_lock.Lock(); if (client_logger == 0) { - client_logtype.add_inc("lsum"); - client_logtype.add_inc("lnum"); - client_logtype.add_inc("lwsum"); - client_logtype.add_inc("lwnum"); - client_logtype.add_inc("lrsum"); - client_logtype.add_inc("lrnum"); - client_logtype.add_inc("trsum"); - client_logtype.add_inc("trnum"); - client_logtype.add_inc("wrlsum"); - client_logtype.add_inc("wrlnum"); - client_logtype.add_inc("lstatsum"); - client_logtype.add_inc("lstatnum"); - client_logtype.add_inc("ldirsum"); - client_logtype.add_inc("ldirnum"); - client_logtype.add_inc("readdir"); - client_logtype.add_inc("stat"); - client_logtype.add_avg("owrlat"); - client_logtype.add_avg("ordlat"); - client_logtype.add_inc("owr"); - client_logtype.add_inc("ord"); + client_logtype.add_inc(l_c_reply, "reply"); + client_logtype.add_avg(l_c_lat, "lat"); + client_logtype.add_avg(l_c_lat, "wrlat"); + client_logtype.add_avg(l_c_lat, "owrlat"); + client_logtype.add_avg(l_c_lat, "ordlat"); char s[80]; char hostname[80]; @@ -922,26 +907,8 @@ MClientReply *Client::make_request(MClientRequest *req, utime_t lat = g_clock.real_now(); lat -= start; dout(20) << "lat " << lat << dendl; - client_logger->finc("lsum",(double)lat); - client_logger->inc("lnum"); - - if (nojournal) { - client_logger->finc("lrsum",(double)lat); - client_logger->inc("lrnum"); - } else { - client_logger->finc("lwsum",(double)lat); - client_logger->inc("lwnum"); - } - - if (op == CEPH_MDS_OP_STAT) { - client_logger->finc("lstatsum",(double)lat); - client_logger->inc("lstatnum"); - } - else if (op == CEPH_MDS_OP_READDIR) { - client_logger->finc("ldirsum",(double)lat); - client_logger->inc("ldirnum"); - } - + client_logger->favg(l_c_lat,(double)lat); + client_logger->favg(l_c_reply,(double)lat); } return reply; @@ -3967,10 +3934,8 @@ int Client::_write(Fh *f, __s64 offset, __u64 size, const char *buf) // time utime_t lat = g_clock.real_now(); lat -= start; - if (client_logger) { - client_logger->finc("wrlsum",(double)lat); - client_logger->inc("wrlnum"); - } + if (client_logger) + client_logger->favg(l_c_wrlat,(double)lat); // assume success for now. FIXME. __u64 totalwritten = size; diff --git a/src/client/Client.h b/src/client/Client.h index 5e44091d4d3f1..868f6c631fbf3 100644 --- a/src/client/Client.h +++ b/src/client/Client.h @@ -16,6 +16,15 @@ #ifndef __CLIENT_H #define __CLIENT_H +enum { + l_c_first = 20000, + l_c_reply, + l_c_lat, + l_c_owrlat, + l_c_ordlat, + l_c_wrlat, + l_c_last, +}; #include "mds/MDSMap.h" #include "osd/OSDMap.h" diff --git a/src/client/SyntheticClient.cc b/src/client/SyntheticClient.cc index a099a8838c9e7..03c4d3ae010c6 100644 --- a/src/client/SyntheticClient.cc +++ b/src/client/SyntheticClient.cc @@ -778,8 +778,8 @@ int SyntheticClient::run() && i > 0 && i < iarg1-1 ) { - client_logger->finc("trsum", (double)lat); - client_logger->inc("trnum"); + //client_logger->finc("trsum", (double)lat); + //client_logger->inc("trnum"); } } dout(1) << "done " << dendl; @@ -1704,7 +1704,6 @@ int SyntheticClient::read_dirs(const char *basedir, int dirs, int files, int dep int r = client->getdir(basedir, contents); utime_t e = g_clock.now(); e -= s; - if (client_logger) client_logger->finc("readdir", e); if (r < 0) { dout(0) << "read_dirs couldn't readdir " << basedir << ", stopping" << dendl; return -1; @@ -1719,7 +1718,6 @@ int SyntheticClient::read_dirs(const char *basedir, int dirs, int files, int dep } utime_t e = g_clock.now(); e -= s; - if (client_logger) client_logger->finc("stat", e); } if (depth > 0) @@ -2172,8 +2170,6 @@ int SyntheticClient::create_objects(int nobj, int osize, int inflight) utime_t lat = g_clock.now(); lat -= starts.front(); starts.pop_front(); - if (client_logger) - client_logger->favg("owrlat", lat); } lock.Lock(); @@ -2280,9 +2276,9 @@ int SyntheticClient::object_rw(int nobj, int osize, int wrpc, lat -= start; if (client_logger) { if (write) - client_logger->favg("owrlat", lat); + client_logger->favg(l_c_owrlat, lat); else - client_logger->favg("ordlat", lat); + client_logger->favg(l_c_ordlat, lat); } } diff --git a/src/common/LogType.h b/src/common/LogType.h index a0889545acb6a..886c177700365 100644 --- a/src/common/LogType.h +++ b/src/common/LogType.h @@ -18,105 +18,48 @@ #include "include/types.h" -#include -#include -using std::string; -using std::ofstream; - -#include -#include -using __gnu_cxx::hash_map; -using __gnu_cxx::hash_set; - -#include "Mutex.h" - +#include +using std::vector; class LogType { protected: - hash_map keymap; - vector keys; - set inc_keys; - vector avg; - - int version; - - // HACK to avoid the hash table as often as possible... - // cache recent key name lookups in a small ring buffer - const static int cache_keys = 10; - intptr_t kc_ptr[cache_keys]; - int kc_val[cache_keys]; - int kc_pos; + int first_key, num_keys; + vector key_name; + vector inc_keys, avg_keys; friend class Logger; public: - LogType() { - version = 1; - - for (int i=0;i= 0) return i; - - i = keys.size(); - keys.push_back(key); - avg.push_back(false); - - intptr_t p = (intptr_t)key; - keymap[p] = i; - if (is_inc) inc_keys.insert(i); - - version++; + int lookup_key(int key, bool isnew=false) { + int i = key - first_key; + assert(i >= 0 && i < num_keys); + assert(isnew || key_name[i]); return i; } - int add_inc(const char* key) { - return add_key(key, true); + void add_key(int key, const char *name, bool is_inc, bool is_avg) { + int i = lookup_key(key, true); + key_name[i] = name; + inc_keys[i] = is_inc; + avg_keys[i] = is_avg; } - int add_set(const char *key) { - return add_key(key, false); + void add_inc(int key, const char *name) { + return add_key(key, name, true, false); } - int add_avg(const char *key) { - int i = add_key(key, true); - avg[i] = true; - return i; - } - - bool have_key(const char* key) { - return lookup_key(key) < 0; + void add_set(int key, const char *name) { + return add_key(key, name, false, false); } - - int lookup_key(const char* key) { - intptr_t p = (intptr_t)key; - - if (keymap.count(p)) - return keymap[p]; - - // try kc ringbuffer - int pos = kc_pos-1; - for (int j=0; jtype = type; - wrote_header = -1; - wrote_header_last = 0; - - version = 0; - - if (logger_list.empty()) { - // init logger - if (!g_conf.clock_tare) - start = g_clock.now(); // time 0! otherwise g_clock does it for us. - - last_flush = 0; - - // call manually the first time; then it'll schedule itself. - flush_all_loggers(); - } - logger_list.push_back(this); } - logger_lock.Unlock(); -} + + filename = g_conf.logger_dir; + filename += "/"; + if (g_conf.log_name) { + filename += g_conf.log_name; + ::mkdir( filename.c_str(), 0755 ); // make sure dir exists + filename += "/"; + } + filename += name; -Logger::~Logger() -{ - logger_lock.Lock(); - { - _flush(); - out.close(); - logger_list.remove(this); // slow, but rare. - if (logger_list.empty()) - logger_event = 0; // stop the timer events. + if (append) + out.open(filename.c_str(), ofstream::out|ofstream::app); + else + out.open(filename.c_str(), ofstream::out); + + if (logger_list.empty()) { + // init logger + if (!g_conf.clock_tare) + start = g_clock.now(); // time 0! otherwise g_clock does it for us. + + last_flush = 0; + + // call manually the first time; then it'll schedule itself. + flush_all_loggers(); } - logger_lock.Unlock(); + logger_list.push_back(this); } -/* -void Logger::flush() +Logger::~Logger() { - logger_lock.Lock(); + Mutex::Locker l(logger_lock); + _flush(); - logger_lock.Unlock(); + out.close(); + logger_list.remove(this); // slow, but rare. + if (logger_list.empty()) + logger_event = 0; // stop the timer events. } -*/ + void Logger::_flush() { // header? wrote_header_last++; - if (wrote_header != type->version || - wrote_header_last > 10) { - out << "#" << type->keymap.size(); - for (unsigned i=0; ikeys.size(); i++) { - out << "\t" << type->keys[i]; - if (type->avg[i]) - out << "\t" << type->keys[i] << "*\t" << type->keys[i] << "~"; + if (wrote_header_last > 10) { + out << "#" << type->num_keys; + for (int i=0; inum_keys; i++) { + out << "\t" << type->key_name[i]; + if (type->avg_keys[i]) + out << "\t" << type->key_name[i] << "*\t" << type->key_name[i] << "~"; } out << std::endl; //out << "\t (" << type->keymap.size() << ")" << endl; - wrote_header = type->version; wrote_header_last = 0; } - maybe_resize(type->keys.size()); - // write line to log out << last_flush; - for (unsigned i=0; ikeys.size(); i++) { - if (type->avg[i]) { + for (int i=0; inum_keys; i++) { + if (type->avg_keys[i]) { if (vals[i] > 0) { double avg = (fvals[i] / (double)vals[i]); double var = 0.0; @@ -222,8 +200,8 @@ void Logger::_flush() out << std::endl; // reset the counters - for (unsigned i=0; ikeys.size(); i++) { - if (type->inc_keys.count(i)) { + for (int i=0; inum_keys; i++) { + if (type->inc_keys[i]) { this->vals[i] = 0; this->fvals[i] = 0; } @@ -232,42 +210,33 @@ void Logger::_flush() -long Logger::inc(const char *key, long v) +long Logger::inc(int key, long v) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - if (i < 0) i = type->add_inc(key); - maybe_resize(i+1); - vals[i] += v; long r = vals[i]; logger_lock.Unlock(); return r; } -double Logger::finc(const char *key, double v) +double Logger::finc(int key, double v) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - if (i < 0) i = type->add_inc(key); - maybe_resize(i+1); - fvals[i] += v; double r = fvals[i]; logger_lock.Unlock(); return r; } -long Logger::set(const char *key, long v) +long Logger::set(int key, long v) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - if (i < 0) i = type->add_set(key); - maybe_resize(i+1); - //cout << this << " set " << i << " to " << v << std::endl; long r = vals[i] = v; logger_lock.Unlock(); @@ -275,28 +244,22 @@ long Logger::set(const char *key, long v) } -double Logger::fset(const char *key, double v) +double Logger::fset(int key, double v) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - if (i < 0) i = type->add_set(key); - maybe_resize(i+1); - //cout << this << " fset " << i << " to " << v << std::endl; double r = fvals[i] = v; logger_lock.Unlock(); return r; } -double Logger::favg(const char *key, double v) +double Logger::favg(int key, double v) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - if (i < 0) i = type->add_avg(key); - maybe_resize(i+1); - vals[i]++; double r = fvals[i] = v; if (g_conf.logger_calc_variance) @@ -305,13 +268,11 @@ double Logger::favg(const char *key, double v) return r; } -long Logger::get(const char* key) +long Logger::get(int key) { if (!g_conf.log) return 0; logger_lock.Lock(); int i = type->lookup_key(key); - maybe_resize(i+1); - long r = 0; if (i >= 0 && i < (int)vals.size()) r = vals[i]; diff --git a/src/common/Logger.h b/src/common/Logger.h index 70fc1fa978024..cc964d5f77ade 100644 --- a/src/common/Logger.h +++ b/src/common/Logger.h @@ -26,47 +26,46 @@ using std::vector; using std::string; using std::ofstream; + #include "LogType.h" class Logger { protected: + // my type + string name, filename; + bool append; + LogType *type; + // values for this instance vector vals; vector fvals; vector< vector > vals_to_avg; - void maybe_resize(unsigned s) { - while (s >= vals.size()) { - vals.push_back(0); - fvals.push_back(0.0); - vals_to_avg.push_back(vector()); - } - } - - // my type - LogType *type; - int version; - - string filename; ofstream out; // what i've written //int last_logged; - int wrote_header; int wrote_header_last; public: - Logger(string fn, LogType *type, bool append=false); + Logger(string n, LogType *t, bool ap=false) : + name(n), append(ap), type(t), + vals(t->num_keys), fvals(t->num_keys), vals_to_avg(t->num_keys), + wrote_header_last(10000) { + _open_log(); + } ~Logger(); - long inc(const char *s, long v = 1); - long set(const char *s, long v); - long get(const char *s); + void _open_log(); + + long inc(int f, long v = 1); + long set(int f, long v); + long get(int f); - double fset(const char *s, double v); - double finc(const char *s, double v); - double favg(const char *s, double v); + double fset(int f, double v); + double finc(int f, double v); + double favg(int f, double v); //void flush(); void _flush(); diff --git a/src/dumpjournal.cc b/src/dumpjournal.cc index 19ca0de3d712b..c67f98b8eaf07 100644 --- a/src/dumpjournal.cc +++ b/src/dumpjournal.cc @@ -100,7 +100,7 @@ int main(int argc, const char **argv, const char *envp[]) log_inode.layout = g_default_mds_log_layout; objecter = new Objecter(messenger, &monmap, &osdmap, lock); - journaler = new Journaler(log_inode.ino, &log_inode.layout, objecter, 0, &lock); + journaler = new Journaler(log_inode.ino, &log_inode.layout, objecter, 0, 0, &lock); objecter->set_client_incarnation(0); diff --git a/src/mds/CDir.cc b/src/mds/CDir.cc index c7972ddda72de..4fec6b6e17aa6 100644 --- a/src/mds/CDir.cc +++ b/src/mds/CDir.cc @@ -631,7 +631,7 @@ void CDir::split(int bits, list& subs, list& waiters, bool repl { dout(10) << "split by " << bits << " bits on " << *this << dendl; - if (cache->mds->logger) cache->mds->logger->inc("dir_sp"); + if (cache->mds->logger) cache->mds->logger->inc(l_mds_dir_sp); assert(is_complete() || !is_auth()); @@ -1034,7 +1034,7 @@ void CDir::fetch(Context *c, bool ignore_authpinnability) auth_pin(this); state_set(CDir::STATE_FETCHING); - if (cache->mds->logger) cache->mds->logger->inc("dir_f"); + if (cache->mds->logger) cache->mds->logger->inc(l_mds_dir_f); // start by reading the first hunk of it C_Dir_Fetch *fin = new C_Dir_Fetch(this); @@ -1360,7 +1360,7 @@ void CDir::_commit(version_t want) // complete? if (!is_complete()) { dout(7) << "commit not complete, fetching first" << dendl; - if (cache->mds->logger) cache->mds->logger->inc("dir_ffc"); + if (cache->mds->logger) cache->mds->logger->inc(l_mds_dir_ffc); fetch(new C_Dir_RetryCommit(this, want)); return; } @@ -1374,7 +1374,7 @@ void CDir::_commit(version_t want) state_set(STATE_COMMITTING); } - if (cache->mds->logger) cache->mds->logger->inc("dir_c"); + if (cache->mds->logger) cache->mds->logger->inc(l_mds_dir_c); // snap purge? SnapRealm *realm = inode->find_snaprealm(); diff --git a/src/mds/MDCache.cc b/src/mds/MDCache.cc index 9c317744c2f55..44b4b9bc3f42b 100644 --- a/src/mds/MDCache.cc +++ b/src/mds/MDCache.cc @@ -127,11 +127,11 @@ void MDCache::log_stat(Logger *logger) //logger->set("pop", (int)get_root()->pop_nested.meta_load(now)); //logger->set("popauth", (int)get_root()->pop_auth_subtree_nested.meta_load(now)); } - logger->set("c", lru.lru_get_size()); - logger->set("cpin", lru.lru_get_num_pinned()); - logger->set("ctop", lru.lru_get_top()); - logger->set("cbot", lru.lru_get_bot()); - logger->set("cptail", lru.lru_get_pintail()); + logger->set(l_mds_c, lru.lru_get_size()); + logger->set(l_mds_cpin, lru.lru_get_num_pinned()); + logger->set(l_mds_ctop, lru.lru_get_top()); + logger->set(l_mds_cbot, lru.lru_get_bot()); + logger->set(l_mds_cptail, lru.lru_get_pintail()); } @@ -4328,7 +4328,7 @@ void MDCache::trim_dentry(CDentry *dn, map& expiremap) if (dir->get_num_head_items() == 0 && dir->is_subtree_root()) migrator->export_empty_import(dir); - if (mds->logger) mds->logger->inc("cex"); + if (mds->logger) mds->logger->inc(l_mds_cex); } @@ -5229,7 +5229,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who return 1; } - if (mds->logger) mds->logger->inc("t"); + if (mds->logger) mds->logger->inc(l_mds_t); // start trace trace.clear(); @@ -5284,7 +5284,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who dout(10) << "traverse: need dirfrag " << fg << ", doing discover from " << *cur << dendl; discover_path(cur, snapid, path.postfixpath(depth), _get_waiter(mdr, req), onfail == MDS_TRAVERSE_DISCOVERXLOCK); - if (mds->logger) mds->logger->inc("tdis"); + if (mds->logger) mds->logger->inc(l_mds_tdis); return 1; } } @@ -5352,7 +5352,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who (dnl->is_null() || !noperm)) { dout(10) << "traverse: xlocked dentry at " << *dn << dendl; dn->lock.add_waiter(SimpleLock::WAIT_RD, _get_waiter(mdr, req)); - if (mds->logger) mds->logger->inc("tlock"); + if (mds->logger) mds->logger->inc(l_mds_tlock); return 1; } @@ -5371,7 +5371,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who dout(7) << "remote link to " << dnl->get_remote_ino() << ", which i don't have" << dendl; assert(mdr); // we shouldn't hit non-primary dentries doing a non-mdr traversal! open_remote_ino(dnl->get_remote_ino(), _get_waiter(mdr, req)); - if (mds->logger) mds->logger->inc("trino"); + if (mds->logger) mds->logger->inc(l_mds_trino); return 1; } } @@ -5468,7 +5468,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who dout(7) << "traverse: incomplete dir contents for " << *cur << ", fetching" << dendl; touch_inode(cur); curdir->fetch(_get_waiter(mdr, req)); - if (mds->logger) mds->logger->inc("tdirf"); + if (mds->logger) mds->logger->inc(l_mds_tdirf); return 1; } } else { @@ -5480,7 +5480,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who dout(7) << "traverse: discover from " << path[depth] << " from " << *curdir << dendl; discover_path(curdir, snapid, path.postfixpath(depth), _get_waiter(mdr, req), onfail == MDS_TRAVERSE_DISCOVERXLOCK); - if (mds->logger) mds->logger->inc("tdis"); + if (mds->logger) mds->logger->inc(l_mds_tdis); return 1; } if (onfail == MDS_TRAVERSE_FORWARD) { @@ -5509,7 +5509,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who else mds->forward_message_mds(req, dauth.first); - if (mds->logger) mds->logger->inc("tfw"); + if (mds->logger) mds->logger->inc(l_mds_tfw); return 2; } if (onfail == MDS_TRAVERSE_FAIL) @@ -5522,7 +5522,7 @@ int MDCache::path_traverse(MDRequest *mdr, Message *req, // who // success. if (psnapid) *psnapid = snapid; - if (mds->logger) mds->logger->inc("thit"); + if (mds->logger) mds->logger->inc(l_mds_thit); return 0; } @@ -5975,8 +5975,8 @@ void MDCache::request_finish(MDRequest *mdr) } if (mdr->client_request && mds->logger) { - mds->logger->inc("reply"); - mds->logger->favg("replyl", g_clock.now() - mdr->client_request->get_recv_stamp()); + mds->logger->inc(l_mds_reply); + mds->logger->favg(l_mds_replyl, g_clock.now() - mdr->client_request->get_recv_stamp()); } delete mdr->client_request; @@ -5992,7 +5992,7 @@ void MDCache::request_forward(MDRequest *mdr, int who, int port) mds->forward_message_mds(mdr->client_request, who); request_cleanup(mdr); - if (mds->logger) mds->logger->inc("fw"); + if (mds->logger) mds->logger->inc(l_mds_fw); } @@ -6084,11 +6084,11 @@ void MDCache::request_cleanup(MDRequest *mdr) // log some stats ***** if (mds->logger) { - mds->logger->set("c", lru.lru_get_size()); - mds->logger->set("cpin", lru.lru_get_num_pinned()); - mds->logger->set("ctop", lru.lru_get_top()); - mds->logger->set("cbot", lru.lru_get_bot()); - mds->logger->set("cptail", lru.lru_get_pintail()); + mds->logger->set(l_mds_c, lru.lru_get_size()); + mds->logger->set(l_mds_cpin, lru.lru_get_num_pinned()); + mds->logger->set(l_mds_ctop, lru.lru_get_top()); + mds->logger->set(l_mds_cbot, lru.lru_get_bot()); + mds->logger->set(l_mds_cptail, lru.lru_get_pintail()); //mds->logger->set("buf",buffer_total_alloc); } diff --git a/src/mds/MDLog.cc b/src/mds/MDLog.cc index ceb209bce452f..63d445a2cb7cd 100644 --- a/src/mds/MDLog.cc +++ b/src/mds/MDLog.cc @@ -34,7 +34,7 @@ // cons/des -LogType mdlog_logtype; +LogType mdlog_logtype(l_mdl_first, l_mdl_last); MDLog::~MDLog() @@ -55,24 +55,23 @@ void MDLog::reopen_logger(utime_t start, bool append) static bool didit = false; if (!didit) { didit = true; - mdlog_logtype.add_inc("evadd"); - mdlog_logtype.add_inc("evex"); - mdlog_logtype.add_inc("evtrm"); - mdlog_logtype.add_set("ev"); - mdlog_logtype.add_set("evexg"); - mdlog_logtype.add_set("evexd"); - - mdlog_logtype.add_inc("segadd"); - mdlog_logtype.add_inc("segex"); - mdlog_logtype.add_inc("segtrm"); - mdlog_logtype.add_set("seg"); - mdlog_logtype.add_set("segexg"); - mdlog_logtype.add_set("segexd"); - - mdlog_logtype.add_set("expos"); - mdlog_logtype.add_set("wrpos"); - mdlog_logtype.add_avg("jacklat"); - mdlog_logtype.add_avg("jsafelat"); + mdlog_logtype.add_inc(l_mdl_evadd, "evadd"); + mdlog_logtype.add_inc(l_mdl_evex, "evex"); + mdlog_logtype.add_inc(l_mdl_evtrm, "evtrm"); + mdlog_logtype.add_set(l_mdl_ev, "ev"); + mdlog_logtype.add_set(l_mdl_evexg, "evexg"); + mdlog_logtype.add_set(l_mdl_evexd, "evexd"); + + mdlog_logtype.add_inc(l_mdl_segadd, "segadd"); + mdlog_logtype.add_inc(l_mdl_segex, "segex"); + mdlog_logtype.add_inc(l_mdl_segtrm, "segtrm"); + mdlog_logtype.add_set(l_mdl_seg, "seg"); + mdlog_logtype.add_set(l_mdl_segexg, "segexg"); + mdlog_logtype.add_set(l_mdl_segexd, "segexd"); + + mdlog_logtype.add_set(l_mdl_expos, "expos"); + mdlog_logtype.add_set(l_mdl_wrpos, "wrpos"); + mdlog_logtype.add_avg(l_mdl_jlat, "jlat"); } } @@ -89,7 +88,9 @@ void MDLog::init_journaler() // log streamer if (journaler) delete journaler; - journaler = new Journaler(log_inode.ino, &log_inode.layout, mds->objecter, logger, &mds->mds_lock); + journaler = new Journaler(log_inode.ino, &log_inode.layout, mds->objecter, + logger, l_mdl_jlat, + &mds->mds_lock); } void MDLog::write_head(Context *c) @@ -121,8 +122,8 @@ void MDLog::create(Context *c) journaler->reset(); write_head(c); - logger->set("expos", journaler->get_expire_pos()); - logger->set("wrpos", journaler->get_write_pos()); + logger->set(l_mdl_expos, journaler->get_expire_pos()); + logger->set(l_mdl_wrpos, journaler->get_write_pos()); } void MDLog::open(Context *c) @@ -140,7 +141,7 @@ void MDLog::append() journaler->set_read_pos(journaler->get_write_pos()); journaler->set_expire_pos(journaler->get_write_pos()); - logger->set("expos", journaler->get_write_pos()); + logger->set(l_mdl_expos, journaler->get_write_pos()); } @@ -184,9 +185,9 @@ void MDLog::submit_entry( LogEvent *le, Context *c, bool wait_safe ) delete le; if (logger) { - logger->inc("evadd"); - logger->set("ev", num_events); - logger->set("wrpos", journaler->get_write_pos()); + logger->inc(l_mdl_evadd); + logger->set(l_mdl_ev, num_events); + logger->set(l_mdl_wrpos, journaler->get_write_pos()); } unflushed++; @@ -279,8 +280,8 @@ void MDLog::start_new_segment(Context *onsync) flush(); } - logger->inc("segadd"); - logger->set("seg", segments.size()); + logger->inc(l_mdl_segadd); + logger->set(l_mdl_seg, segments.size()); } void MDLog::_logged_subtree_map(loff_t off) @@ -358,8 +359,8 @@ void MDLog::try_expire(LogSegment *ls) _expired(ls); } - logger->set("segexg", expiring_segments.size()); - logger->set("evexg", expiring_events); + logger->set(l_mdl_segexg, expiring_segments.size()); + logger->set(l_mdl_evexg, expiring_events); } void MDLog::_maybe_expired(LogSegment *ls) @@ -385,8 +386,8 @@ void MDLog::_expired(LogSegment *ls) expired_segments.insert(ls); expired_events += ls->num_events; - logger->inc("evex", ls->num_events); - logger->inc("segex"); + logger->inc(l_mdl_evex, ls->num_events); + logger->inc(l_mdl_segex); // trim expired segments? while (!segments.empty()) { @@ -403,19 +404,19 @@ void MDLog::_expired(LogSegment *ls) journaler->set_expire_pos(ls->offset); // this was the oldest segment, adjust expire pos journaler->write_head(0); - logger->set("expos", ls->offset); - logger->inc("segtrm"); - logger->inc("evtrm", ls->num_events); + logger->set(l_mdl_expos, ls->offset); + logger->inc(l_mdl_segtrm); + logger->inc(l_mdl_evtrm, ls->num_events); segments.erase(ls->offset); delete ls; } } - logger->set("ev", num_events); - logger->set("evexd", expired_events); - logger->set("seg", segments.size()); - logger->set("segexd", expired_segments.size()); + logger->set(l_mdl_ev, num_events); + logger->set(l_mdl_evexd, expired_events); + logger->set(l_mdl_seg, segments.size()); + logger->set(l_mdl_segexd, expired_segments.size()); } @@ -504,7 +505,7 @@ void MDLog::_replay_thread() // new segment? if (le->get_type() == EVENT_SUBTREEMAP) { segments[pos] = new LogSegment(pos); - logger->set("seg", segments.size()); + logger->set(l_mdl_seg, segments.size()); } // have we seen an import map yet? @@ -526,7 +527,7 @@ void MDLog::_replay_thread() } delete le; - logger->set("rdpos", pos); + logger->set(l_mdl_rdpos, pos); // drop lock for a second, so other events/messages (e.g. beacon timer!) can go off mds->mds_lock.Unlock(); @@ -541,7 +542,7 @@ void MDLog::_replay_thread() // move read pointer _back_ to first subtree map we saw, for eventual trimming journaler->set_read_pos(new_expire_pos); journaler->set_expire_pos(new_expire_pos); - logger->set("expos", new_expire_pos); + logger->set(l_mdl_expos, new_expire_pos); } // kick waiter(s) diff --git a/src/mds/MDLog.h b/src/mds/MDLog.h index f78938af97325..6fd03567628ec 100644 --- a/src/mds/MDLog.h +++ b/src/mds/MDLog.h @@ -16,6 +16,27 @@ #ifndef __MDLOG_H #define __MDLOG_H +enum { + l_mdl_first = 5000, + l_mdl_evadd, + l_mdl_evex, + l_mdl_evtrm, + l_mdl_ev, + l_mdl_evexg, + l_mdl_evexd, + l_mdl_segadd, + l_mdl_segex, + l_mdl_segtrm, + l_mdl_seg, + l_mdl_segexg, + l_mdl_segexd, + l_mdl_expos, + l_mdl_wrpos, + l_mdl_rdpos, + l_mdl_jlat, + l_mdl_last, +}; + #include "include/types.h" #include "include/Context.h" diff --git a/src/mds/MDS.cc b/src/mds/MDS.cc index f161799b85269..133742dece6b2 100644 --- a/src/mds/MDS.cc +++ b/src/mds/MDS.cc @@ -151,17 +151,20 @@ MDS::~MDS() { void MDS::reopen_logger(utime_t start) { - static LogType mds_logtype, mds_cache_logtype; + static LogType mds_logtype(l_mds_first, l_mds_last); + static LogType mds_cache_logtype(l_mdc_first, l_mdc_last); + static bool didit = false; if (!didit) { didit = true; - //mds_logtype.add_inc("req"); - mds_logtype.add_inc("reply"); - mds_logtype.add_inc("fw"); + mds_logtype.add_inc(l_mds_req, "req"); + mds_logtype.add_inc(l_mds_reply, "reply"); + mds_logtype.add_avg(l_mds_replyl, "replyl"); + mds_logtype.add_inc(l_mds_fw, "fw"); - mds_logtype.add_inc("dir_f"); - mds_logtype.add_inc("dir_c"); + mds_logtype.add_inc(l_mds_dir_f, "dir_f"); + mds_logtype.add_inc(l_mds_dir_c, "dir_c"); //mds_logtype.add_inc("mkdir"); /* @@ -178,44 +181,42 @@ void MDS::reopen_logger(utime_t start) mds_logtype.add_inc("dirt5"); */ - mds_logtype.add_set("c"); - mds_logtype.add_set("ctop"); - mds_logtype.add_set("cbot"); - mds_logtype.add_set("cptail"); - mds_logtype.add_set("cpin"); - mds_logtype.add_inc("cex"); - mds_logtype.add_inc("dis"); - - mds_logtype.add_inc("t"); - mds_logtype.add_inc("thit"); - mds_logtype.add_inc("tfw"); - mds_logtype.add_inc("tdis"); - mds_logtype.add_inc("tdirf"); - mds_logtype.add_inc("trino"); - mds_logtype.add_inc("tlock"); + mds_logtype.add_set(l_mds_c, "c"); + mds_logtype.add_set(l_mds_ctop, "ctop"); + mds_logtype.add_set(l_mds_cbot, "cbot"); + mds_logtype.add_set(l_mds_cptail, "cptail"); + mds_logtype.add_set(l_mds_cpin, "cpin"); + mds_logtype.add_inc(l_mds_cex, "cex"); + mds_logtype.add_inc(l_mds_dis, "dis"); + + mds_logtype.add_inc(l_mds_t, "t"); + mds_logtype.add_inc(l_mds_thit, "thit"); + mds_logtype.add_inc(l_mds_tfw, "tfw"); + mds_logtype.add_inc(l_mds_tdis, "tdis"); + mds_logtype.add_inc(l_mds_tdirf, "tdirf"); + mds_logtype.add_inc(l_mds_trino, "trino"); + mds_logtype.add_inc(l_mds_tlock, "tlock"); - mds_logtype.add_set("l"); - mds_logtype.add_set("q"); - mds_logtype.add_set("popanyd"); - mds_logtype.add_set("popnest"); + mds_logtype.add_set(l_mds_l, "l"); + mds_logtype.add_set(l_mds_q, "q"); + mds_logtype.add_set(l_mds_popanyd, "popanyd"); + mds_logtype.add_set(l_mds_popnest, "popnest"); - mds_logtype.add_set("buf"); + mds_logtype.add_set(l_mds_buf, "buf"); - mds_logtype.add_set("sm"); - mds_logtype.add_inc("ex"); - mds_logtype.add_inc("iex"); - mds_logtype.add_inc("im"); - mds_logtype.add_inc("iim"); + mds_logtype.add_set(l_mds_sm, "sm"); + mds_logtype.add_inc(l_mds_ex, "ex"); + mds_logtype.add_inc(l_mds_iex, "iex"); + mds_logtype.add_inc(l_mds_im, "im"); + mds_logtype.add_inc(l_mds_iim, "iim"); /* mds_logtype.add_inc("imex"); mds_logtype.add_set("nex"); mds_logtype.add_set("nim"); */ - mds_logtype.add_avg("replyl"); - } - + if (whoami < 0) return; // flush+close old log @@ -398,12 +399,12 @@ void MDS::tick() mds_load_t load = balancer->get_load(); if (logger) { - req_rate = logger->get("req"); + req_rate = logger->get(l_mds_req); - logger->fset("l", (int)load.mds_load()); - logger->set("q", messenger->get_dispatch_queue_len()); - logger->set("buf", buffer_total_alloc.test()); - logger->set("sm", mdcache->num_subtrees()); + logger->fset(l_mds_l, (int)load.mds_load()); + logger->set(l_mds_q, messenger->get_dispatch_queue_len()); + logger->set(l_mds_buf, buffer_total_alloc.test()); + logger->set(l_mds_sm, mdcache->num_subtrees()); mdcache->log_stat(logger); } diff --git a/src/mds/MDS.h b/src/mds/MDS.h index 929a376ee6494..57b439326ca5e 100644 --- a/src/mds/MDS.h +++ b/src/mds/MDS.h @@ -35,6 +35,50 @@ #include "SessionMap.h" +enum { + l_mds_first = 2000, + l_mds_req, + l_mds_reply, + l_mds_replyl, + l_mds_fw, + l_mds_dir_f, + l_mds_dir_c, + l_mds_dir_sp, + l_mds_dir_ffc, + l_mds_c, + l_mds_ctop, + l_mds_cbot, + l_mds_cptail, + l_mds_cpin, + l_mds_cex, + l_mds_dis, + l_mds_t, + l_mds_thit, + l_mds_tfw, + l_mds_tdis, + l_mds_tdirf, + l_mds_trino, + l_mds_tlock, + l_mds_l, + l_mds_q, + l_mds_popanyd, + l_mds_popnest, + l_mds_buf, + l_mds_sm, + l_mds_ex, + l_mds_iex, + l_mds_im, + l_mds_iim, + l_mds_last, +}; + +enum { + l_mdc_first = 3000, + l_mdc_last, +}; + + + class filepath; class OSDMap; diff --git a/src/mds/Migrator.cc b/src/mds/Migrator.cc index 0cef1c7002d85..361542f8824fd 100644 --- a/src/mds/Migrator.cc +++ b/src/mds/Migrator.cc @@ -846,8 +846,8 @@ void Migrator::export_go_synced(CDir *dir) mds->send_message_mds(req, dest); // stats - if (mds->logger) mds->logger->inc("ex"); - if (mds->logger) mds->logger->inc("iex", num_exported_inodes); + if (mds->logger) mds->logger->inc(l_mds_ex); + if (mds->logger) mds->logger->inc(l_mds_iex, num_exported_inodes); cache->show_subtrees(); } @@ -1699,8 +1699,8 @@ void Migrator::handle_export_dir(MExportDir *m) // some stats if (mds->logger) { - mds->logger->inc("im"); - mds->logger->inc("iim", num_imported_inodes); + mds->logger->inc(l_mds_im); + mds->logger->inc(l_mds_iim, num_imported_inodes); } delete m; diff --git a/src/mds/Server.cc b/src/mds/Server.cc index 48b3ca624ff1f..41f40d81ca2e1 100644 --- a/src/mds/Server.cc +++ b/src/mds/Server.cc @@ -67,15 +67,15 @@ using namespace std; void Server::reopen_logger(utime_t start, bool append) { - static LogType mdserver_logtype; + static LogType mdserver_logtype(l_mdss_first, l_mdss_last); static bool didit = false; if (!didit) { didit = true; - mdserver_logtype.add_inc("hcreq"); // handle client req - mdserver_logtype.add_inc("hsreq"); // slave - mdserver_logtype.add_inc("hcsess"); // client session - mdserver_logtype.add_inc("dcreq"); // dispatch client req - mdserver_logtype.add_inc("dsreq"); // slave + mdserver_logtype.add_inc(l_mdss_hcreq,"hcreq"); // handle client req + mdserver_logtype.add_inc(l_mdss_hsreq, "hsreq"); // slave + mdserver_logtype.add_inc(l_mdss_hcsess, "hcsess"); // client session + mdserver_logtype.add_inc(l_mdss_dcreq, "dcreq"); // dispatch client req + mdserver_logtype.add_inc(l_mdss_dsreq, "dsreq"); // slave } if (logger) @@ -806,7 +806,7 @@ void Server::handle_client_request(MClientRequest *req) { dout(4) << "handle_client_request " << *req << dendl; - if (logger) logger->inc("hcreq"); + if (logger) logger->inc(l_mdss_hcreq); if (!mds->is_active() && !(mds->is_stopping() && req->get_orig_source().is_mds())) { @@ -869,7 +869,7 @@ void Server::dispatch_client_request(MDRequest *mdr) { MClientRequest *req = mdr->client_request; - if (logger) logger->inc("dcreq"); + if (logger) logger->inc(l_mdss_dcreq); if (mdr->ref) { dout(7) << "dispatch_client_request " << *req << " ref " << *mdr->ref << dendl; @@ -985,7 +985,7 @@ void Server::handle_slave_request(MMDSSlaveRequest *m) dout(4) << "handle_slave_request " << m->get_reqid() << " from " << m->get_source() << dendl; int from = m->get_source().num(); - if (logger) logger->inc("hsreq"); + if (logger) logger->inc(l_mdss_hsreq); // reply? if (m->is_reply()) { @@ -1081,7 +1081,7 @@ void Server::dispatch_slave_request(MDRequest *mdr) return; } - if (logger) logger->inc("dsreq"); + if (logger) logger->inc(l_mdss_dsreq); switch (mdr->slave_request->get_op()) { case MMDSSlaveRequest::OP_XLOCK: diff --git a/src/mds/Server.h b/src/mds/Server.h index 83ccf793cc89c..77b71d0746dc7 100644 --- a/src/mds/Server.h +++ b/src/mds/Server.h @@ -26,7 +26,15 @@ class EUpdate; class MMDSSlaveRequest; struct SnapInfo; - +enum { + l_mdss_first = 1000, + l_mdss_hcreq, + l_mdss_hsreq, + l_mdss_hcsess, + l_mdss_dcreq, + l_mdss_dsreq, + l_mdss_last, +}; class Server { MDS *mds; diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc index b9e5a97c9fc96..40ffdf3bb928d 100644 --- a/src/osd/OSD.cc +++ b/src/osd/OSD.cc @@ -213,8 +213,6 @@ int OSD::peek_super(const char *dev, nstring& magic, ceph_fsid_t& fsid, int& who // cons/des -LogType osd_logtype; - OSD::OSD(int id, Messenger *m, Messenger *hbm, MonMap *mm, const char *dev, const char *jdev) : osd_lock("OSD::osd_lock"), timer(osd_lock), @@ -335,49 +333,50 @@ int OSD::init() return -EINVAL; // log + static LogType osd_logtype(l_osd_first, l_osd_last); char name[80]; sprintf(name, "osd%d", whoami); logger = new Logger(name, (LogType*)&osd_logtype); - osd_logtype.add_set("opq"); - osd_logtype.add_inc("op"); - osd_logtype.add_inc("c_rd"); - osd_logtype.add_inc("c_rdb"); - osd_logtype.add_inc("c_wr"); - osd_logtype.add_inc("c_wrb"); + osd_logtype.add_set(l_osd_opq, "opq"); + osd_logtype.add_inc(l_osd_op, "op"); + osd_logtype.add_inc(l_osd_c_rd, "c_rd"); + osd_logtype.add_inc(l_osd_c_rdb, "c_rdb"); + osd_logtype.add_inc(l_osd_c_wr, "c_wr"); + osd_logtype.add_inc(l_osd_c_wrb,"c_wrb"); - osd_logtype.add_inc("r_wr"); - osd_logtype.add_inc("r_wrb"); + osd_logtype.add_inc(l_osd_r_wr, "r_wr"); + osd_logtype.add_inc(l_osd_r_wrb, "r_wrb"); - osd_logtype.add_inc("r_push"); - osd_logtype.add_inc("r_pushb"); - osd_logtype.add_inc("r_pull"); - osd_logtype.add_inc("r_pullb"); + osd_logtype.add_inc(l_osd_r_push, "r_push"); + osd_logtype.add_inc(l_osd_r_pushb, "r_pushb"); + osd_logtype.add_inc(l_osd_r_pull, "r_pull"); + osd_logtype.add_inc(l_osd_r_pullb, "r_pullb"); - osd_logtype.add_set("qlen"); - osd_logtype.add_set("rqlen"); - osd_logtype.add_set("rdlat"); - osd_logtype.add_set("rdlatm"); - osd_logtype.add_set("fshdin"); - osd_logtype.add_set("fshdout"); - osd_logtype.add_inc("shdout"); - osd_logtype.add_inc("shdin"); - - osd_logtype.add_set("loadavg"); - - osd_logtype.add_inc("rlsum"); - osd_logtype.add_inc("rlnum"); - - osd_logtype.add_set("numpg"); - osd_logtype.add_set("hbto"); - osd_logtype.add_set("hbfrom"); + osd_logtype.add_set(l_osd_qlen, "qlen"); + osd_logtype.add_set(l_osd_rqlen, "rqlen"); + osd_logtype.add_set(l_osd_rdlat, "rdlat"); + osd_logtype.add_set(l_osd_rdlatm, "rdlatm"); + osd_logtype.add_set(l_osd_fshdin, "fshdin"); + osd_logtype.add_set(l_osd_fshdout, "fshdout"); + osd_logtype.add_inc(l_osd_shdout, "shdout"); + osd_logtype.add_inc(l_osd_shdin, "shdin"); + + osd_logtype.add_set(l_osd_loadavg, "loadavg"); + + osd_logtype.add_inc(l_osd_rlsum, "rlsum"); + osd_logtype.add_inc(l_osd_rlnum, "rlnum"); + + osd_logtype.add_set(l_osd_numpg, "numpg"); + osd_logtype.add_set(l_osd_hbto, "hbto"); + osd_logtype.add_set(l_osd_hbfrom, "hbfrom"); - osd_logtype.add_set("buf"); + osd_logtype.add_set(l_osd_buf, "buf"); - osd_logtype.add_inc("map"); - osd_logtype.add_inc("mapi"); - osd_logtype.add_inc("mapidup"); - osd_logtype.add_inc("mapf"); - osd_logtype.add_inc("mapfdup"); + osd_logtype.add_inc(l_osd_map, "map"); + osd_logtype.add_inc(l_osd_mapi, "mapi"); + osd_logtype.add_inc(l_osd_mapidup, "mapidup"); + osd_logtype.add_inc(l_osd_mapf, "mapf"); + osd_logtype.add_inc(l_osd_mapfdup, "mapfdup"); // i'm ready! messenger->set_dispatcher(this); @@ -828,12 +827,12 @@ void OSD::_refresh_my_stat(utime_t now) my_stat.read_latency_mine = my_stat.read_latency * (1.0 - frac_rd_ops_shed_in); - logger->fset("qlen", my_stat.qlen); - logger->fset("rqlen", my_stat.recent_qlen); - logger->fset("rdlat", my_stat.read_latency); - logger->fset("rdlatm", my_stat.read_latency_mine); - logger->fset("fshdin", my_stat.frac_rd_ops_shed_in); - logger->fset("fshdout", my_stat.frac_rd_ops_shed_out); + logger->fset(l_osd_qlen, my_stat.qlen); + logger->fset(l_osd_rqlen, my_stat.recent_qlen); + logger->fset(l_osd_rdlat, my_stat.read_latency); + logger->fset(l_osd_rdlatm, my_stat.read_latency_mine); + logger->fset(l_osd_fshdin, my_stat.frac_rd_ops_shed_in); + logger->fset(l_osd_fshdout, my_stat.frac_rd_ops_shed_out); dout(30) << "_refresh_my_stat " << my_stat << dendl; stat_rd_ops = 0; @@ -1003,7 +1002,7 @@ void OSD::heartbeat() if (in.is_open()) { float oneminavg; in >> oneminavg; - logger->fset("loadavg", oneminavg); + logger->fset(l_osd_loadavg, oneminavg); in.close(); } @@ -1057,8 +1056,8 @@ void OSD::heartbeat() } } - if (logger) logger->set("hbto", heartbeat_to.size()); - if (logger) logger->set("hbfrom", heartbeat_from.size()); + if (logger) logger->set(l_osd_hbto, heartbeat_to.size()); + if (logger) logger->set(l_osd_hbfrom, heartbeat_from.size()); // hmm.. am i all alone? @@ -1713,7 +1712,7 @@ void OSD::handle_osd_map(MOSDMap *m) ObjectStore::Transaction t; - logger->inc("mapmsg"); + logger->inc(l_osd_map); // store them? for (map::iterator p = m->maps.begin(); @@ -1722,7 +1721,7 @@ void OSD::handle_osd_map(MOSDMap *m) pobject_t poid = get_osdmap_pobject_name(p->first); if (store->exists(0, poid)) { dout(10) << "handle_osd_map already had full map epoch " << p->first << dendl; - logger->inc("mapfdup"); + logger->inc(l_osd_mapfdup); bufferlist bl; get_map_bl(p->first, bl); dout(10) << " .. it is " << bl.length() << " bytes" << dendl; @@ -1740,7 +1739,7 @@ void OSD::handle_osd_map(MOSDMap *m) superblock.oldest_map == 0) superblock.oldest_map = p->first; - logger->inc("mapf"); + logger->inc(l_osd_mapf); } for (map::iterator p = m->incremental_maps.begin(); p != m->incremental_maps.end(); @@ -1748,7 +1747,7 @@ void OSD::handle_osd_map(MOSDMap *m) pobject_t poid = get_inc_osdmap_pobject_name(p->first); if (store->exists(0, poid)) { dout(10) << "handle_osd_map already had incremental map epoch " << p->first << dendl; - logger->inc("mapidup"); + logger->inc(l_osd_mapidup); bufferlist bl; get_inc_map_bl(p->first, bl); dout(10) << " .. it is " << bl.length() << " bytes" << dendl; @@ -1766,7 +1765,7 @@ void OSD::handle_osd_map(MOSDMap *m) superblock.oldest_map == 0) superblock.oldest_map = p->first; - logger->inc("mapi"); + logger->inc(l_osd_mapi); } // advance if we can @@ -2148,7 +2147,7 @@ void OSD::activate_map(ObjectStore::Transaction& t) do_queries(query_map); do_infos(info_map); - logger->set("numpg", pg_map.size()); + logger->set(l_osd_numpg, pg_map.size()); wake_all_pg_waiters(); // the pg mapping may have shifted @@ -3310,7 +3309,7 @@ void OSD::handle_op(MOSDOp *op) PG *pg = _have_pg(pgid) ? _lookup_lock_pg(pgid):0; - logger->set("buf", buffer_total_alloc.test()); + logger->set(l_osd_buf, buffer_total_alloc.test()); utime_t now = g_clock.now(); @@ -3545,7 +3544,7 @@ void OSD::enqueue_op(PG *pg, Message *op) // add to pg's op_queue pg->op_queue.push_back(op); pending_ops++; - logger->set("opq", pending_ops); + logger->set(l_osd_opq, pending_ops); // add pg to threadpool queue pg->get(); // we're exposing the pointer, here. @@ -3607,7 +3606,7 @@ void OSD::dequeue_op(PG *pg) op_queue_cond.Signal(); pending_ops--; - logger->set("opq", pending_ops); + logger->set(l_osd_opq, pending_ops); if (pending_ops == 0 && waiting_for_no_ops) no_pending_ops.Signal(); } diff --git a/src/osd/OSD.h b/src/osd/OSD.h index c29e3ee9b18fe..07cd7a1a98c78 100644 --- a/src/osd/OSD.h +++ b/src/osd/OSD.h @@ -40,6 +40,44 @@ using namespace std; using namespace __gnu_cxx; +enum { + l_osd_first = 10000, + l_osd_opq, + l_osd_op, + l_osd_c_rd, + l_osd_c_rdb, + l_osd_c_wr, + l_osd_c_wrb, + l_osd_r_wr, + l_osd_r_wrb, + l_osd_subop, + l_osd_r_push, + l_osd_r_pushb, + l_osd_r_pull, + l_osd_r_pullb, + l_osd_qlen, + l_osd_rqlen, + l_osd_rdlat, + l_osd_rdlatm, + l_osd_fshdin, + l_osd_fshdout, + l_osd_shdout, + l_osd_shdin, + l_osd_loadavg, + l_osd_rlsum, + l_osd_rlnum, + l_osd_numpg, + l_osd_hbto, + l_osd_hbfrom, + l_osd_buf, + l_osd_map, + l_osd_mapi, + l_osd_mapidup, + l_osd_mapf, + l_osd_mapfdup, + l_osd_last, +}; + class Messenger; class Message; class Logger; diff --git a/src/osd/ReplicatedPG.cc b/src/osd/ReplicatedPG.cc index 73ef69ec2d782..343c0aa71c1d1 100644 --- a/src/osd/ReplicatedPG.cc +++ b/src/osd/ReplicatedPG.cc @@ -330,7 +330,7 @@ bool ReplicatedPG::preprocess_op(MOSDOp *op, utime_t now) op->set_peer_stat(osd->my_stat); osd->messenger->forward_message(op, osd->osdmap->get_inst(shedto)); osd->stat_rd_ops_shed_out++; - osd->logger->inc("shdout"); + osd->logger->inc(l_osd_shdout); return true; } } @@ -373,7 +373,7 @@ void ReplicatedPG::do_op(MOSDOp *op) { //dout(15) << "do_op " << *op << dendl; - osd->logger->inc("op"); + osd->logger->inc(l_osd_op); if (op->is_modify()) op_modify(op); @@ -386,7 +386,7 @@ void ReplicatedPG::do_sub_op(MOSDSubOp *op) { dout(15) << "do_sub_op " << *op << dendl; - osd->logger->inc("subop"); + osd->logger->inc(l_osd_subop); if (op->ops.size() >= 1) { ceph_osd_op& first = op->ops[0]; @@ -673,7 +673,7 @@ void ReplicatedPG::op_read(MOSDOp *op) << ", them = " << op->get_peer_stat().read_latency << (osd->my_stat.read_latency_mine > op->get_peer_stat().read_latency ? " WTF":"") << dendl; - osd->logger->inc("shdin"); + osd->logger->inc(l_osd_shdin); // does it look like they were wrong to do so? Mutex::Locker lock(osd->peer_stat_lock); @@ -733,8 +733,8 @@ void ReplicatedPG::op_read(MOSDOp *op) } dout(10) << " read got " << r << " / " << p->length << " bytes from obj " << oid << dendl; } - osd->logger->inc("c_rd"); - osd->logger->inc("c_rdb", p->length); + osd->logger->inc(l_osd_c_rd); + osd->logger->inc(l_osd_c_rdb, p->length); break; case CEPH_OSD_OP_STAT: @@ -1459,8 +1459,8 @@ void ReplicatedPG::eval_repop(RepGather *repop) utime_t now = g_clock.now(); now -= repop->start; - osd->logger->finc("rlsum", now); - osd->logger->inc("rlnum", 1); + osd->logger->finc(l_osd_rlsum, now); + osd->logger->inc(l_osd_rlnum, 1); } // done. @@ -1745,8 +1745,8 @@ void ReplicatedPG::op_modify(MOSDOp *op) } if (op->get_data().length()) { - osd->logger->inc("c_wr"); - osd->logger->inc("c_wrb", op->get_data().length()); + osd->logger->inc(l_osd_c_wr); + osd->logger->inc(l_osd_c_wrb, op->get_data().length()); } // note my stats @@ -1878,8 +1878,8 @@ void ReplicatedPG::sub_op_modify(MOSDSubOp *op) // do op int ackerosd = acting[0]; - osd->logger->inc("r_wr"); - osd->logger->inc("r_wrb", op->get_data().length()); + osd->logger->inc(l_osd_r_wr); + osd->logger->inc(l_osd_r_wrb, op->get_data().length()); if (!op->noop) { object_info_t oi(op->poid); @@ -2259,8 +2259,8 @@ void ReplicatedPG::push(pobject_t poid, int peer, << " to osd" << peer << dendl; - osd->logger->inc("r_push"); - osd->logger->inc("r_pushb", bl.length()); + osd->logger->inc(l_osd_r_push); + osd->logger->inc(l_osd_r_pushb, bl.length()); // send osd_reqid_t rid; // useless? @@ -2496,8 +2496,8 @@ void ReplicatedPG::sub_op_push(MOSDSubOp *op) unsigned r = osd->store->apply_transaction(t); assert(r == 0); - osd->logger->inc("r_pull"); - osd->logger->inc("r_pullb", data.length()); + osd->logger->inc(l_osd_r_pull); + osd->logger->inc(l_osd_r_pullb, data.length()); if (is_primary()) { diff --git a/src/osdc/Journaler.cc b/src/osdc/Journaler.cc index 0d605e4c2ddf2..b1da5f4f5abe5 100644 --- a/src/osdc/Journaler.cc +++ b/src/osdc/Journaler.cc @@ -215,7 +215,7 @@ void Journaler::_finish_flush(int r, __s64 start, utime_t stamp, bool safe) if (logger) { utime_t lat = g_clock.now(); lat -= stamp; - logger->favg(safe ? "jsafelat" : "jacklat", lat); + logger->favg(logger_key_lat, lat); } // adjust ack_pos diff --git a/src/osdc/Journaler.h b/src/osdc/Journaler.h index 9c56cdf904b03..f98a676891821 100644 --- a/src/osdc/Journaler.h +++ b/src/osdc/Journaler.h @@ -94,6 +94,7 @@ public: Filer filer; Logger *logger; + int logger_key_lat; Mutex *lock; SafeTimer timer; @@ -189,9 +190,9 @@ public: friend class C_Trim; public: - Journaler(inodeno_t ino_, ceph_file_layout *layout_, Objecter *obj, Logger *l, Mutex *lk, __s64 fl=0, __s64 pff=0) : + Journaler(inodeno_t ino_, ceph_file_layout *layout_, Objecter *obj, Logger *l, int lkey, Mutex *lk, __s64 fl=0, __s64 pff=0) : ino(ino_), layout(*layout_), - objecter(obj), filer(objecter), logger(l), + objecter(obj), filer(objecter), logger(l), logger_key_lat(lkey), lock(lk), timer(*lk), delay_flush_event(0), state(STATE_UNDEF), error(0), write_pos(0), flush_pos(0), ack_pos(0), safe_pos(0), -- 2.39.5