From f2ead26e7b347e1c5c25c11e964a24b2afc26894 Mon Sep 17 00:00:00 2001 From: Colin Patrick McCabe Date: Wed, 1 Dec 2010 14:57:51 -0800 Subject: [PATCH] logging: better syntax for LogClient Rather than having to write logclient.log(LOG_ERROR, ss), coders can now write clog.error() << "str". Auto-flushing, if enabled, is still handled automatically. Rename instances of LogClient to clog (central log) for consistency and brevity. Signed-off-by: Colin McCabe --- src/common/LogClient.cc | 26 +++++++--- src/common/LogClient.h | 102 ++++++++++++++++++++++++++++++---------- src/include/LogEntry.h | 28 +++++------ src/mds/CDir.cc | 21 ++++----- src/mds/CInode.cc | 36 +++++++------- src/mds/InoTable.cc | 10 ++-- src/mds/Locker.cc | 5 +- src/mds/MDCache.cc | 39 +++++++-------- src/mds/MDS.cc | 26 ++++------ src/mds/MDS.h | 2 +- src/mds/Server.cc | 27 +++++------ src/mds/journal.cc | 14 +++--- src/mon/LogMonitor.cc | 12 ++--- src/mon/MDSMonitor.cc | 5 +- src/mon/Monitor.cc | 15 ++---- src/mon/Monitor.h | 4 +- src/mon/OSDMonitor.cc | 18 ++----- src/mon/PGMonitor.cc | 5 +- src/mon/Paxos.cc | 12 ++--- src/osd/OSD.cc | 69 ++++++++++----------------- src/osd/OSD.h | 4 +- src/osd/PG.cc | 88 +++++++++++++++++++--------------- src/osd/ReplicatedPG.cc | 18 +++---- 23 files changed, 295 insertions(+), 291 deletions(-) diff --git a/src/common/LogClient.cc b/src/common/LogClient.cc index 921adcc5485e2..179b04c0704a9 100644 --- a/src/common/LogClient.cc +++ b/src/common/LogClient.cc @@ -37,25 +37,37 @@ #include "config.h" -void LogClient::log(log_type type, const char *s) +LogClientTemp::LogClientTemp(clog_type type_, LogClient &parent_) + : type(type_), parent(parent_) { - string str(s); - log(type, str); } -void LogClient::log(log_type type, stringstream& ss) +LogClientTemp::LogClientTemp(const LogClientTemp &rhs) + : type(rhs.type), parent(rhs.parent) +{ + // don't want to-- nor can we-- copy the ostringstream +} + +LogClientTemp::~LogClientTemp() +{ + if (ss.peek() != EOF) + parent.do_log(type, ss); +} + +void LogClient::do_log(clog_type type, std::stringstream& ss) { while (!ss.eof()) { string s; getline(ss, s); - log(type, s); + if (!s.empty()) + do_log(type, s); } } -void LogClient::log(log_type type, string& s) +void LogClient::do_log(clog_type type, const std::string& s) { Mutex::Locker l(log_lock); - dout(0) << "log " << (log_type)type << " : " << s << dendl; + dout(0) << "log " << type << " : " << s << dendl; LogEntry e; e.who = messenger->get_myinst(); e.stamp = g_clock.now(); diff --git a/src/common/LogClient.h b/src/common/LogClient.h index a6584739f6451..4a0e1f3b87d9d 100644 --- a/src/common/LogClient.h +++ b/src/common/LogClient.h @@ -20,46 +20,100 @@ #include "common/Mutex.h" #include "include/LogEntry.h" +#include #include -class Messenger; +class LogClient; class MLog; class MLogAck; -class MonMap; +class Messenger; class MonClient; +class MonMap; -class LogClient : public Dispatcher { - Messenger *messenger; - MonMap *monmap; - MonClient *monc; +class LogClientTemp +{ +public: + LogClientTemp(clog_type type_, LogClient &parent_); + LogClientTemp(const LogClientTemp &rhs); + ~LogClientTemp(); + + template + std::ostream& operator<<(const T& rhs) + { + return ss << rhs; + } + +private: + clog_type type; + LogClient &parent; + stringstream ss; +}; + +class LogClient : public Dispatcher +{ +public: + enum logclient_flag_t { + NO_FLAGS = 0, + FLAG_SYNC = 0x1, + }; + + LogClient(Messenger *m, MonMap *mm, MonClient *mc, enum logclient_flag_t flags) : + messenger(m), monmap(mm), monc(mc), is_synchronous(flags & FLAG_SYNC), + log_lock("LogClient::log_lock"), last_log(0) { } + + void send_log(); + void handle_log_ack(MLogAck *m); + void set_synchronous(bool sync) { is_synchronous = sync; } + LogClientTemp debug() { + return LogClientTemp(CLOG_DEBUG, *this); + } + void debug(std::stringstream &s) { + do_log(CLOG_DEBUG, s); + } + LogClientTemp info() { + return LogClientTemp(CLOG_INFO, *this); + } + void info(std::stringstream &s) { + do_log(CLOG_INFO, s); + } + LogClientTemp warn() { + return LogClientTemp(CLOG_WARN, *this); + } + void warn(std::stringstream &s) { + do_log(CLOG_WARN, s); + } + LogClientTemp error() { + return LogClientTemp(CLOG_ERROR, *this); + } + void error(std::stringstream &s) { + do_log(CLOG_ERROR, s); + } + LogClientTemp sec() { + return LogClientTemp(CLOG_SEC, *this); + } + void sec(std::stringstream &s) { + do_log(CLOG_SEC, s); + } + +private: + void do_log(clog_type type, std::stringstream& ss); + void do_log(clog_type type, const std::string& s); bool ms_dispatch(Message *m); - bool is_synchronous; void _send_log(); - void ms_handle_connect(Connection *con); - bool ms_handle_reset(Connection *con) { return false; } void ms_handle_remote_reset(Connection *con) {} - - public: - - // -- log -- + Messenger *messenger; + MonMap *monmap; + MonClient *monc; + bool is_synchronous; Mutex log_lock; - deque log_queue; version_t last_log; + deque log_queue; - void log(log_type type, const char *s); - void log(log_type type, string& s); - void log(log_type type, stringstream& s); - void send_log(); - void handle_log_ack(MLogAck *m); - void set_synchronous(bool sync) { is_synchronous = sync; } - - LogClient(Messenger *m, MonMap *mm, MonClient *mc=0) : - messenger(m), monmap(mm), monc(mc), is_synchronous(false), - log_lock("LogClient::log_lock"), last_log(0) { } + friend class LogClientTemp; }; #endif diff --git a/src/include/LogEntry.h b/src/include/LogEntry.h index 1cc02bcb27477..db5c2e7c34190 100644 --- a/src/include/LogEntry.h +++ b/src/include/LogEntry.h @@ -19,12 +19,12 @@ #include "include/encoding.h" typedef enum { - LOG_DEBUG = 0, - LOG_INFO = 1, - LOG_SEC = 2, - LOG_WARN = 3, - LOG_ERROR = 4, -} log_type; + CLOG_DEBUG = 0, + CLOG_INFO = 1, + CLOG_SEC = 2, + CLOG_WARN = 3, + CLOG_ERROR = 4, +} clog_type; struct LogEntryKey { entity_inst_t who; @@ -55,7 +55,7 @@ struct LogEntry { entity_inst_t who; utime_t stamp; uint64_t seq; - log_type type; + clog_type type; string msg; LogEntryKey key() const { return LogEntryKey(who, stamp, seq); } @@ -78,7 +78,7 @@ struct LogEntry { ::decode(stamp, bl); ::decode(seq, bl); ::decode(t, bl); - type = (log_type)t; + type = (clog_type)t; ::decode(msg, bl); } }; @@ -118,18 +118,18 @@ struct LogSummary { }; WRITE_CLASS_ENCODER(LogSummary) -inline ostream& operator<<(ostream& out, const log_type& t) +inline ostream& operator<<(ostream& out, const clog_type& t) { switch (t) { - case LOG_DEBUG: + case CLOG_DEBUG: return out << "[DBG]"; - case LOG_INFO: + case CLOG_INFO: return out << "[INF]"; - case LOG_WARN: + case CLOG_WARN: return out << "[WRN]"; - case LOG_ERROR: + case CLOG_ERROR: return out << "[ERR]"; - case LOG_SEC: + case CLOG_SEC: return out << "[SEC]"; default: return out << "[???]"; diff --git a/src/mds/CDir.cc b/src/mds/CDir.cc index 62ee0619fb3bf..fdacb6c9f5525 100644 --- a/src/mds/CDir.cc +++ b/src/mds/CDir.cc @@ -1206,6 +1206,7 @@ void CDir::fetch(Context *c, const string& want_dn, bool ignore_authpinnability) void CDir::_fetched(bufferlist &bl, const string& want_dn) { + LogClient &clog = cache->mds->clog; dout(10) << "_fetched " << bl.length() << " bytes for " << *this << " want_dn=" << want_dn @@ -1217,9 +1218,8 @@ void CDir::_fetched(bufferlist &bl, const string& want_dn) // empty?!? if (bl.length() == 0) { dout(0) << "_fetched missing object for " << *this << dendl; - stringstream ss; - ss << "dir " << ino() << "." << dirfrag() << " object missing on disk; some files may be lost"; - cache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "dir " << ino() << "." << dirfrag() + << " object missing on disk; some files may be lost\n"; log_mark_dirty(); @@ -1384,14 +1384,14 @@ void CDir::_fetched(bufferlist &bl, const string& want_dn) dout(-12) << "_fetched badness: got (but i already had) " << *in << " mode " << in->inode.mode << " mtime " << in->inode.mtime << dendl; - stringstream ss; string dirpath, inopath; this->inode->make_path_string(dirpath); in->make_path_string(inopath); - ss << "loaded dup inode " << inode.ino << " [" << first << "," << last << "] v" << inode.version - << " at " << dirpath << "/" << dname - << ", but inode " << in->vino() << " v" << in->inode.version << " already exists at " << inopath; - cache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "loaded dup inode " << inode.ino + << " [" << first << "," << last << "] v" << inode.version + << " at " << dirpath << "/" << dname + << ", but inode " << in->vino() << " v" << in->inode.version + << " already exists at " << inopath << "\n"; continue; } else { // inode @@ -1462,9 +1462,8 @@ void CDir::_fetched(bufferlist &bl, const string& want_dn) } } if (!p.end()) { - stringstream ss; - ss << "dir " << dirfrag() << " has " << bl.length() - p.get_off() << " extra bytes"; - cache->mds->logclient.log(LOG_WARN, ss); + clog.warn() << "dir " << dirfrag() << " has " + << bl.length() - p.get_off() << " extra bytes\n"; } //cache->mds->logger->inc("newin", num_new_inodes_loaded); diff --git a/src/mds/CInode.cc b/src/mds/CInode.cc index 401530d8da1a3..6f6f7b108d0fe 100644 --- a/src/mds/CInode.cc +++ b/src/mds/CInode.cc @@ -1560,6 +1560,8 @@ void CInode::_finish_frag_update(CDir *dir, Mutation *mut) /* for more info on scatterlocks, see comments by Locker::scatter_writebehind */ void CInode::finish_scatter_gather_update(int type) { + LogClient &clog = mdcache->mds->clog; + dout(10) << "finish_scatter_gather_update " << type << " on " << *this << dendl; assert(is_auth()); @@ -1596,9 +1598,8 @@ void CInode::finish_scatter_gather_update(int type) if (pf->fragstat.nfiles < 0 || pf->fragstat.nsubdirs < 0) { - stringstream ss; - ss << "bad/negative dir size on " << dir->dirfrag() << " " << pf->fragstat; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "bad/negative dir size on " + << dir->dirfrag() << " " << pf->fragstat << "\n"; if (pf->fragstat.nfiles < 0) pf->fragstat.nfiles = 0; @@ -1616,10 +1617,9 @@ void CInode::finish_scatter_gather_update(int type) if (fg == frag_t()) { // i.e., we are the only frag if (pi->dirstat.size() != pf->fragstat.size()) { - stringstream ss; - ss << "unmatched fragstat size on single dirfrag " << dir->dirfrag() - << ", inode has " << pi->dirstat << ", dirfrag has " << pf->fragstat; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "unmatched fragstat size on single " + << "dirfrag " << dir->dirfrag() << ", inode has " + << pi->dirstat << ", dirfrag has " << pf->fragstat << "\n"; // trust the dirfrag for now version_t v = pi->dirstat.version; @@ -1636,9 +1636,8 @@ void CInode::finish_scatter_gather_update(int type) if (pi->dirstat.nfiles < 0 || pi->dirstat.nsubdirs < 0) { - stringstream ss; - ss << "bad/negative dir size on " << ino() << ", inode has " << pi->dirstat; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "bad/negative dir size on " << ino() + << ", inode has " << pi->dirstat << "\n"; if (pi->dirstat.nfiles < 0) pi->dirstat.nfiles = 0; @@ -1699,10 +1698,9 @@ void CInode::finish_scatter_gather_update(int type) if (fg == frag_t()) { // i.e., we are the only frag if (pi->rstat.rbytes != pf->rstat.rbytes) { - stringstream ss; - ss << "unmatched rstat rbytes on single dirfrag " << dir->dirfrag() - << ", inode has " << pi->rstat << ", dirfrag has " << pf->rstat; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "unmatched rstat rbytes on single dirfrag " + << dir->dirfrag() << ", inode has " << pi->rstat + << ", dirfrag has " << pf->rstat << "\n"; // trust the dirfrag for now version_t v = pi->rstat.version; @@ -1717,17 +1715,15 @@ void CInode::finish_scatter_gather_update(int type) //assert(pi->rstat.rfiles >= 0); if (pi->rstat.rfiles < 0) { - stringstream ss; - ss << "rfiles underflow " << pi->rstat.rfiles << " on " << *this; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "rfiles underflow " << pi->rstat.rfiles + << " on " << *this << "\n"; pi->rstat.rfiles = 0; } //assert(pi->rstat.rsubdirs >= 0); if (pi->rstat.rsubdirs < 0) { - stringstream ss; - ss << "rsubdirs underflow " << pi->rstat.rfiles << " on " << *this; - mdcache->mds->logclient.log(LOG_ERROR, ss); + clog.error() << "rsubdirs underflow " << pi->rstat.rfiles + << " on " << *this << "\n"; pi->rstat.rsubdirs = 0; } } diff --git a/src/mds/InoTable.cc b/src/mds/InoTable.cc index aacb1282e2f8d..be43f41f9a60f 100644 --- a/src/mds/InoTable.cc +++ b/src/mds/InoTable.cc @@ -104,9 +104,8 @@ void InoTable::replay_alloc_id(inodeno_t id) free.erase(id); projected_free.erase(id); } else { - stringstream ss; - ss << "journal replay alloc " << id << " not in free " << free; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << "journal replay alloc " << id + << " not in free " << free << "\n"; } projected_version = ++version; } @@ -119,9 +118,8 @@ void InoTable::replay_alloc_ids(interval_set& ids) free.subtract(ids); projected_free.subtract(ids); } else { - stringstream ss; - ss << "journal replay alloc " << ids << ", only " << is << " is in free " << free; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << "journal replay alloc " << ids << ", only " + << is << " is in free " << free << "\n"; free.subtract(is); projected_free.subtract(is); } diff --git a/src/mds/Locker.cc b/src/mds/Locker.cc index 1cddcf83f9267..16bd367742401 100644 --- a/src/mds/Locker.cc +++ b/src/mds/Locker.cc @@ -2080,9 +2080,8 @@ void Locker::process_request_cap_release(MDRequest *mdr, client_t client, const dn->remove_client_lease(l, this); } } else { - stringstream ss; - ss << "client" << client << " released lease on dn " << dir->dirfrag() << "/" << dname << " which dne"; - mds->logclient.log(LOG_WARN, ss); + mds->clog.warn() << "client" << client << " released lease on dn " + << dir->dirfrag() << "/" << dname << " which dne\n"; } } } diff --git a/src/mds/MDCache.cc b/src/mds/MDCache.cc index 2519953b476f4..8dab245658021 100644 --- a/src/mds/MDCache.cc +++ b/src/mds/MDCache.cc @@ -1909,10 +1909,9 @@ void MDCache::predirty_journal_parents(Mutation *mut, EMetaBlob *blob, assert(!"negative dirstat size" == g_conf.mds_verify_scatter); if (parent->get_frag() == frag_t()) { // i.e., we are the only frag if (pi->dirstat.size() != pf->fragstat.size()) { - stringstream ss; - ss << "unmatched fragstat size on single dirfrag " << parent->dirfrag() - << ", inode has " << pi->dirstat << ", dirfrag has " << pf->fragstat; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << "unmatched fragstat size on single dirfrag " + << parent->dirfrag() << ", inode has " << pi->dirstat + << ", dirfrag has " << pf->fragstat << "\n"; // trust the dirfrag for now pi->dirstat = pf->fragstat; @@ -1957,10 +1956,9 @@ void MDCache::predirty_journal_parents(Mutation *mut, EMetaBlob *blob, if (parent->get_frag() == frag_t()) { // i.e., we are the only frag if (pi->rstat.rbytes != pf->rstat.rbytes) { - stringstream ss; - ss << "unmatched rstat rbytes on single dirfrag " << parent->dirfrag() - << ", inode has " << pi->rstat << ", dirfrag has " << pf->rstat; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << "unmatched rstat rbytes on single dirfrag " + << parent->dirfrag() << ", inode has " << pi->rstat + << ", dirfrag has " << pf->rstat << "\n"; // trust the dirfrag for now pi->rstat = pf->rstat; @@ -4707,9 +4705,8 @@ void MDCache::do_file_recover() // blech if (pi->client_ranges.size() && !pi->get_max_size()) { - stringstream ss; - ss << "bad client_range " << pi->client_ranges << " on ino " << pi->ino; - mds->logclient.log(LOG_WARN, ss); + mds->clog.warn() << "bad client_range " << pi->client_ranges + << " on ino " << pi->ino << "\n"; } if (pi->client_ranges.size() && pi->get_max_size()) { @@ -5159,7 +5156,7 @@ void MDCache::trim_inode(CDentry *dn, CInode *in, CDir *con, map >::iterator p = subtrees.begin(); @@ -5200,12 +5197,11 @@ void MDCache::trim_non_auth() else if (dnl->is_primary()) { CInode *in = dnl->get_inode(); list ls; - warn_string_dirs << in->get_parent_dn()->get_name() << std::endl; + warn_str_dirs << in->get_parent_dn()->get_name() << "\n"; in->get_dirfrags(ls); for (list::iterator p = ls.begin(); p != ls.end(); ++p) { CDir *subdir = *p; - warn_string_dirs << subdir->get_inode()->get_parent_dn()->get_name() - << std::endl; + warn_str_dirs << subdir->get_inode()->get_parent_dn()->get_name() << "\n"; if (subdir->is_subtree_root()) remove_subtree(subdir); in->close_dirfrag(subdir->dirfrag().frag); @@ -5247,15 +5243,14 @@ void MDCache::trim_non_auth() p != ls.end(); ++p) { dout(0) << " ... " << **p << dendl; - warn_string_dirs << (*p)->get_inode()->get_parent_dn()->get_name() - << std::endl; + warn_str_dirs << (*p)->get_inode()->get_parent_dn()->get_name() << "\n"; assert((*p)->get_num_ref() == 1); // SUBTREE remove_subtree((*p)); in->close_dirfrag((*p)->dirfrag().frag); } dout(0) << " ... " << *in << dendl; if (in->get_parent_dn()) - warn_string_dirs << in->get_parent_dn()->get_name() << std::endl; + warn_str_dirs << in->get_parent_dn()->get_name() << "\n"; assert(in->get_num_ref() == 0); remove_inode(in); } @@ -5264,11 +5259,9 @@ void MDCache::trim_non_auth() } show_subtrees(); - if (warn_string_dirs.peek() != EOF) { - stringstream warn_string; - warn_string << "trim_non_auth has deleted paths: " << std::endl; - warn_string << warn_string_dirs; - mds->logclient.log(LOG_INFO, warn_string); + if (warn_str_dirs.peek() != EOF) { + mds->clog.info() << "trim_non_auth has deleted paths: " << "\n"; + mds->clog.info(warn_str_dirs); } } diff --git a/src/mds/MDS.cc b/src/mds/MDS.cc index 30dccd81a6b2b..3d20d4e7791ff 100644 --- a/src/mds/MDS.cc +++ b/src/mds/MDS.cc @@ -83,7 +83,7 @@ MDS::MDS(const char *n, Messenger *m, MonClient *mc) : standby_for_rank(-1), messenger(m), monc(mc), - logclient(messenger, &mc->monmap, mc), + clog(messenger, &mc->monmap, mc, LogClient::NO_FLAGS), sessionmap(this) { orig_argc = 0; @@ -439,7 +439,7 @@ int MDS::init(int wanted_state) dout(10) << sizeof(xlist::item) << "\t xlist<>::item *2=" << 2*sizeof(xlist::item) << dendl; messenger->add_dispatcher_tail(this); - messenger->add_dispatcher_head(&logclient); + messenger->add_dispatcher_head(&clog); // get monmap monc->set_messenger(messenger); @@ -496,7 +496,7 @@ void MDS::tick() _dout_check_log(); - logclient.send_log(); + clog.send_log(); utime_t now = g_clock.now(); utime_t delay = now; @@ -740,18 +740,16 @@ void MDS::handle_command(MMonCommand *m) } else dout(0) << "bad migrate_dir target syntax" << dendl; } else dout(0) << "bad migrate_dir syntax" << dendl; } else if (m->cmd.size() == 1 && m->cmd[0] == "heapdump"){ - stringstream ss; if (g_conf.tcmalloc_have) { if (!g_conf.profiler_running()) { - ss << g_conf.name << " can't dump heap: profiler not running"; + clog.info() << g_conf.name << " can't dump heap: profiler not running\n"; } else { - ss << g_conf.name << " dumping heap profile now"; + clog.info() << g_conf.name << " dumping heap profile now\n"; g_conf.profiler_dump("admin request"); } } else { - ss << "tcmalloc not enabled, can't use profiler"; + clog.info() << "tcmalloc not enabled, can't use profiler\n"; } - logclient.log(LOG_INFO, ss); } else if (m->cmd.size() == 1 && m->cmd[0] == "enable_profiler_options") { char val[sizeof(int)*8+1]; snprintf(val, sizeof(val), "%i", g_conf.profiler_allocation_interval); @@ -760,22 +758,16 @@ void MDS::handle_command(MMonCommand *m) snprintf(val, sizeof(val), "%i", g_conf.profiler_highwater_interval); setenv("HEAP_PROFILE_INUSE_INTERVAL", val, g_conf.profiler_highwater_interval); - stringstream ss; - ss << g_conf.name << " set heap variables from current config"; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " set heap variables from current config\n"; } else if (m->cmd.size() == 1 && m->cmd[0] == "start_profiler") { char location[PATH_MAX]; snprintf(location, sizeof(location), "%s/%s", g_conf.log_dir, g_conf.name); g_conf.profiler_start(location); - stringstream ss; - ss << g_conf.name << " started profiler"; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " started profiler\n"; } else if (m->cmd.size() == 1 && m->cmd[0] == "stop_profiler") { g_conf.profiler_stop(); - stringstream ss; - ss << g_conf.name << " stopped profiler"; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " stopped profiler\n"; } else dout(0) << "unrecognized command! " << m->cmd << dendl; m->put(); diff --git a/src/mds/MDS.h b/src/mds/MDS.h index 868bc78a008af..8b982cf7202f5 100644 --- a/src/mds/MDS.h +++ b/src/mds/MDS.h @@ -155,7 +155,7 @@ class MDS : public Dispatcher { OSDMap *osdmap; Objecter *objecter; Filer *filer; // for reading/writing to/from osds - LogClient logclient; + LogClient clog; // sub systems Server *server; diff --git a/src/mds/Server.cc b/src/mds/Server.cc index 0e04b0cdce0ee..1159b5bfe3ebb 100644 --- a/src/mds/Server.cc +++ b/src/mds/Server.cc @@ -471,12 +471,10 @@ void Server::find_idle_sessions() break; } - stringstream ss; utime_t age = now; age -= session->last_cap_renew; - ss << "closing stale session " << session->inst << " after " << age; - mds->logclient.log(LOG_INFO, ss); - + mds->clog.info() << "closing stale session " << session->inst + << " after " << age << "\n"; dout(10) << "autoclosing stale session " << session->inst << " last " << session->last_cap_renew << dendl; kill_session(session); } @@ -534,7 +532,6 @@ void Server::handle_client_reconnect(MClientReconnect *m) return; } - stringstream ss; utime_t delay = g_clock.now(); delay -= reconnect_start; dout(10) << " reconnect_start " << reconnect_start << " delay " << delay << dendl; @@ -542,10 +539,10 @@ void Server::handle_client_reconnect(MClientReconnect *m) if (!mds->is_reconnect()) { // XXX maybe in the future we can do better than this? dout(1) << " no longer in reconnect state, ignoring reconnect, sending close" << dendl; - ss << "denied reconnect attempt (mds is " << ceph_mds_state_name(mds->get_state()) + mds->clog.info() << "denied reconnect attempt (mds is " + << ceph_mds_state_name(mds->get_state()) << ") from " << m->get_source_inst() - << " after " << delay << " (allowed interval " << g_conf.mds_reconnect_timeout << ")"; - mds->logclient.log(LOG_INFO, ss); + << " after " << delay << " (allowed interval " << g_conf.mds_reconnect_timeout << ")\n"; mds->messenger->send_message(new MClientSession(CEPH_SESSION_CLOSE), m->get_connection()); m->put(); return; @@ -563,11 +560,12 @@ void Server::handle_client_reconnect(MClientReconnect *m) mdlog->start_submit_entry(new ESession(session->inst, true, pv), new C_MDS_session_finish(mds, session, sseq, true, pv)); mdlog->flush(); - ss << "reconnect by new " << session->inst << " after " << delay; + mds->clog.debug() << "reconnect by new " << session->inst + << " after " << delay << "\n"; } else { - ss << "reconnect by " << session->inst << " after " << delay; + mds->clog.debug() << "reconnect by " << session->inst + << " after " << delay << "\n"; } - mds->logclient.log(LOG_DEBUG, ss); // snaprealms for (vector::iterator p = m->realms.begin(); @@ -1634,10 +1632,9 @@ CInode* Server::prepare_new_inode(MDRequest *mdr, CDir *dir, inodeno_t useino, u if (useino && useino != in->inode.ino) { dout(0) << "WARNING: client specified " << useino << " and i allocated " << in->inode.ino << dendl; - stringstream ss; - ss << mdr->client_request->get_source() << " specified ino " << useino - << " but mds" << mds->whoami << " allocated " << in->inode.ino; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << mdr->client_request->get_source() + << " specified ino " << useino + << " but mds" << mds->whoami << " allocated " << in->inode.ino << "\n"; //assert(0); // just for now. } diff --git a/src/mds/journal.cc b/src/mds/journal.cc index 486356b7ccbe2..4325721af16ff 100644 --- a/src/mds/journal.cc +++ b/src/mds/journal.cc @@ -463,8 +463,8 @@ void EMetaBlob::replay(MDS *mds, LogSegment *logseg) ss << "EMetaBlob.replay FIXME had dentry linked to wrong inode " << *dn << " " << *old_in << " should be " << p->inode.ino; - dout(-10) << ss << dendl; - mds->logclient.log(LOG_WARN, ss); + dout(-10) << ss.str() << dendl; + mds->clog.warn(ss); dir->unlink_inode(dn); mds->mdcache->remove_inode_recursive(old_in); @@ -579,9 +579,8 @@ void EMetaBlob::replay(MDS *mds, LogSegment *logseg) // [repair bad inotable updates] if (inotablev > mds->inotable->get_version()) { - stringstream ss; - ss << "journal replay inotablev mismatch " << mds->inotable->get_version() << " -> " << inotablev; - mds->logclient.log(LOG_ERROR, ss); + mds->clog.error() << "journal replay inotablev mismatch " + << mds->inotable->get_version() << " -> " << inotablev << "\n"; mds->inotable->force_replay_version(inotablev); } @@ -605,9 +604,8 @@ void EMetaBlob::replay(MDS *mds, LogSegment *logseg) inodeno_t next = session->next_ino(); inodeno_t i = session->take_ino(used_preallocated_ino); if (next != i) { - stringstream ss; - ss << " replayed op " << client_reqs << " used ino " << i << " but session next is " << next; - mds->logclient.log(LOG_WARN, ss); + mds->clog.warn() << " replayed op " << client_reqs << " used ino " << i + << " but session next is " << next << "\n"; } assert(i == used_preallocated_ino); session->used_inos.clear(); diff --git a/src/mon/LogMonitor.cc b/src/mon/LogMonitor.cc index 1f2cd1c294a4c..105e5835f677b 100644 --- a/src/mon/LogMonitor.cc +++ b/src/mon/LogMonitor.cc @@ -83,7 +83,7 @@ void LogMonitor::create_initial(bufferlist& bl) LogEntry e; memset(&e.who, 0, sizeof(e.who)); e.stamp = g_clock.now(); - e.type = LOG_ERROR; + e.type = CLOG_ERROR; e.msg = "mkfs"; e.seq = 0; pending_log.insert(pair(e.stamp, e)); @@ -134,15 +134,15 @@ bool LogMonitor::update_from_paxos() s += "\n"; blog.append(s); - if (le.type >= LOG_DEBUG) + if (le.type >= CLOG_DEBUG) blogdebug.append(s); - if (le.type >= LOG_INFO) + if (le.type >= CLOG_INFO) bloginfo.append(s); - if (le.type == LOG_SEC) + if (le.type == CLOG_SEC) blogsec.append(s); - if (le.type >= LOG_WARN) + if (le.type >= CLOG_WARN) blogwarn.append(s); - if (le.type >= LOG_ERROR) + if (le.type >= CLOG_ERROR) blogerr.append(s); summary.add(le); diff --git a/src/mon/MDSMonitor.cc b/src/mon/MDSMonitor.cc index adec992414c4f..9832addd0c006 100644 --- a/src/mon/MDSMonitor.cc +++ b/src/mon/MDSMonitor.cc @@ -404,9 +404,8 @@ bool MDSMonitor::should_propose(double& delay) void MDSMonitor::_updated(MMDSBeacon *m) { dout(10) << "_updated " << m->get_orig_source() << " " << *m << dendl; - stringstream ss; - ss << m->get_orig_source_inst() << " " << ceph_mds_state_name(m->get_state()); - mon->get_logclient()->log(LOG_INFO, ss); + mon->clog.info() << m->get_orig_source_inst() << " " + << ceph_mds_state_name(m->get_state()) << "\n"; if (m->get_state() == MDSMap::STATE_STOPPED) { // send the map manually (they're out of the map, so they won't get it automatic) diff --git a/src/mon/Monitor.cc b/src/mon/Monitor.cc index dbaad25963378..a9036b332db73 100644 --- a/src/mon/Monitor.cc +++ b/src/mon/Monitor.cc @@ -95,7 +95,7 @@ Monitor::Monitor(string nm, MonitorStore *s, Messenger *m, MonMap *map) : lock("Monitor::lock"), timer(lock), monmap(map), - logclient(messenger, monmap), + clog(messenger, monmap, NULL, LogClient::FLAG_SYNC), store(s), state(STATE_STARTING), stopping(false), @@ -163,11 +163,9 @@ void Monitor::init() for (vector::iterator ps = paxos_service.begin(); ps != paxos_service.end(); ps++) (*ps)->init(); - logclient.set_synchronous(true); - // i'm ready! messenger->add_dispatcher_tail(this); - messenger->add_dispatcher_head(&logclient); + messenger->add_dispatcher_head(&clog); // start ticker timer.init(); @@ -208,9 +206,7 @@ void Monitor::call_election(bool is_new) rank = monmap->get_rank(name); if (is_new) { - stringstream ss; - ss << "mon." << name << " calling new monitor election"; - logclient.log(LOG_INFO, ss); + clog.info() << "mon." << name << " calling new monitor election\n"; } dout(10) << "call_election" << dendl; @@ -253,9 +249,8 @@ void Monitor::win_election(epoch_t epoch, set& active) quorum = active; dout(10) << "win_election, epoch " << epoch << " quorum is " << quorum << dendl; - stringstream ss; - ss << "mon." << name << "@" << rank << " won leader election with quorum " << quorum; - logclient.log(LOG_INFO, ss); + clog.info() << "mon." << name << "@" << rank + << " won leader election with quorum " << quorum << "\n"; for (vector::iterator p = paxos.begin(); p != paxos.end(); p++) (*p)->leader_init(); diff --git a/src/mon/Monitor.h b/src/mon/Monitor.h index 0c1b1c5e11c95..358bcfc010445 100644 --- a/src/mon/Monitor.h +++ b/src/mon/Monitor.h @@ -67,7 +67,7 @@ public: MonMap *monmap; - LogClient logclient; + LogClient clog; KeyServer key_server; private: @@ -227,8 +227,6 @@ public: void stop_cluster(); int mkfs(bufferlist& osdmapbl); - - LogClient *get_logclient() { return &logclient; } }; int strict_strtol(const char *str, int base, std::string *err); diff --git a/src/mon/OSDMonitor.cc b/src/mon/OSDMonitor.cc index 36df5c10c1948..6297ebeb6de1b 100644 --- a/src/mon/OSDMonitor.cc +++ b/src/mon/OSDMonitor.cc @@ -374,12 +374,10 @@ bool OSDMonitor::preprocess_failure(MOSDFailure *m) bool OSDMonitor::prepare_failure(MOSDFailure *m) { - stringstream ss; dout(1) << "prepare_failure " << m->get_target() << " from " << m->get_orig_source_inst() << " is reporting failure:" << m->if_osd_failed() << dendl; - - ss << m->get_target() << " failed (by " << m->get_orig_source_inst() << ")"; - mon->get_logclient()->log(LOG_INFO, ss); + mon->clog.info() << m->get_target() << " failed (by " + << m->get_orig_source_inst() << ")\n"; int target_osd = m->get_target().name.num(); int reporter = m->get_orig_source().num(); @@ -569,9 +567,7 @@ void OSDMonitor::_booted(MOSDBoot *m, bool logit) << " w " << m->sb.weight << " from " << m->sb.current_epoch << dendl; if (logit) { - stringstream ss; - ss << m->get_orig_source_inst() << " boot"; - mon->get_logclient()->log(LOG_INFO, ss); + mon->clog.info() << m->get_orig_source_inst() << " boot\n"; } send_latest(m, m->sb.current_epoch+1); @@ -618,9 +614,7 @@ bool OSDMonitor::prepare_alive(MOSDAlive *m) int from = m->get_orig_source().num(); if (0) { // we probably don't care much about these - stringstream ss; - ss << m->get_orig_source_inst() << " alive"; - mon->get_logclient()->log(LOG_DEBUG, ss); + mon->clog.debug() << m->get_orig_source_inst() << " alive\n"; } dout(7) << "prepare_alive e" << m->map_epoch << " from " << m->get_orig_source_inst() << dendl; @@ -932,9 +926,7 @@ void OSDMonitor::tick() pending_inc.new_weight[o] = CEPH_OSD_OUT; do_propose = true; - stringstream ss; - ss << "osd" << o << " out (down for " << down << ")"; - mon->get_logclient()->log(LOG_INFO, ss); + mon->clog.info() << "osd" << o << " out (down for " << down << ")\n"; } else continue; } diff --git a/src/mon/PGMonitor.cc b/src/mon/PGMonitor.cc index 0e6fc312eb837..b919407dc27e6 100644 --- a/src/mon/PGMonitor.cc +++ b/src/mon/PGMonitor.cc @@ -387,9 +387,8 @@ bool PGMonitor::prepare_pg_stats(MPGStats *stats) << " state " << pg_state_string(p->second.state) << " but DNE in pg_map!!" << dendl; - stringstream ss; - ss << "got " << pgid << " pg_stat from osd" << from << " but dne in pg_map"; - mon->logclient.log(LOG_ERROR, ss); + mon->clog.error() << "got " << pgid << " pg_stat from osd" << from + << " but dne in pg_map\n"; continue; } diff --git a/src/mon/Paxos.cc b/src/mon/Paxos.cc index 8058f1119a461..1db74b17f86b3 100644 --- a/src/mon/Paxos.cc +++ b/src/mon/Paxos.cc @@ -577,12 +577,10 @@ void Paxos::handle_lease(MMonPaxos *lease) utime_t warn_diff = g_clock.now() - last_clock_drift_warn; if (warn_diff > pow(g_conf.mon_clock_drift_warn_backoff, clock_drift_warned)) { - stringstream ss; - ss << "lease_expire from mon" << lease->get_source().num() + mon->clog.warn() << "lease_expire from mon" << lease->get_source().num() << " was sent from future time " << lease->sent_timestamp << " with expected time <=" << allowed_time - << ", clocks not synchronized"; - mon->get_logclient()->log(LOG_WARN, ss); + << ", clocks not synchronized\n"; last_clock_drift_warn = g_clock.now(); ++clock_drift_warned; } @@ -655,12 +653,10 @@ void Paxos::handle_lease_ack(MMonPaxos *ack) utime_t warn_diff = g_clock.now() - last_clock_drift_warn; if (warn_diff > pow(g_conf.mon_clock_drift_warn_backoff, clock_drift_warned)) { - stringstream ss; - ss << "lease_ack from mon" << from + mon->clog.warn() << "lease_ack from mon" << from << " was sent from future time " << ack->sent_timestamp << " with allowed time <=" << allowed_time - << ", clocks not synchronized."; - mon->get_logclient()->log(LOG_WARN, ss); + << ", clocks not synchronized.\n"; last_clock_drift_warn = g_clock.now(); ++clock_drift_warned; } diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc index 0be95ff57ea30..dbdb0481aa51a 100644 --- a/src/osd/OSD.cc +++ b/src/osd/OSD.cc @@ -342,7 +342,7 @@ OSD::OSD(int id, Messenger *internal_messenger, Messenger *external_messenger, M logger(NULL), logger_started(false), store(NULL), map_in_progress(false), - logclient(client_messenger, &mc->monmap, mc), + clog(client_messenger, &mc->monmap, mc, LogClient::NO_FLAGS), whoami(id), dev_path(dev), journal_path(jdev), dispatch_running(false), @@ -518,7 +518,7 @@ int OSD::init() // i'm ready! client_messenger->add_dispatcher_head(this); - client_messenger->add_dispatcher_head(&logclient); + client_messenger->add_dispatcher_head(&clog); cluster_messenger->add_dispatcher_head(this); heartbeat_messenger->add_dispatcher_head(&heartbeat_dispatcher); @@ -1562,7 +1562,7 @@ void OSD::tick() map_lock.put_read(); - logclient.send_log(); + clog.send_log(); timer.add_event_after(1.0, new C_Tick(this)); @@ -1835,59 +1835,50 @@ void OSD::handle_command(MMonCommand *m) stringstream ss; uint64_t rate = (double)count / (end - start); - ss << "bench: wrote " << prettybyte_t(count) << " in blocks of " << prettybyte_t(bsize) - << " in " << (end-start) - << " sec at " << prettybyte_t(rate) << "/sec"; - logclient.log(LOG_INFO, ss); + clog.info() << "bench: wrote " << prettybyte_t(count) + << " in blocks of " << prettybyte_t(bsize) << " in " + << (end-start) << " sec at " << prettybyte_t(rate) << "/sec\n"; } else if (m->cmd.size() == 2 && m->cmd[0] == "logger" && m->cmd[1] == "reset") { logger_reset_all(); } else if (m->cmd.size() == 2 && m->cmd[0] == "logger" && m->cmd[1] == "reopen") { logger_reopen_all(); } else if (m->cmd.size() == 1 && m->cmd[0] == "heapdump") { - stringstream ss; if (g_conf.tcmalloc_have) { if (!g_conf.profiler_running()) { - ss << "can't dump heap: profiler not running"; + clog.info() << "can't dump heap: profiler not running\n"; } else { - ss << g_conf.name << "dumping heap profile now"; + clog.info() << g_conf.name << "dumping heap profile now\n"; g_conf.profiler_dump("admin request"); } } else { - ss << g_conf.name << " does not have tcmalloc, can't use profiler"; + clog.info() << g_conf.name << " does not have tcmalloc, " + "can't use profiler\n"; } - logclient.log(LOG_INFO, ss); } else if (m->cmd.size() == 1 && m->cmd[0] == "enable_profiler_options") { char val[sizeof(int)*8+1]; snprintf(val, sizeof(val), "%i", g_conf.profiler_allocation_interval); setenv("HEAP_PROFILE_ALLOCATION_INTERVAL", val, g_conf.profiler_allocation_interval); snprintf(val, sizeof(val), "%i", g_conf.profiler_highwater_interval); setenv("HEAP_PROFILE_INUSE_INTERVAL", val, g_conf.profiler_highwater_interval); - stringstream ss; - ss << g_conf.name << " set heap variables from current config"; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " set heap variables from current config"; } else if (m->cmd.size() == 1 && m->cmd[0] == "start_profiler") { char location[PATH_MAX]; snprintf(location, sizeof(location), "%s/%s", g_conf.log_dir, g_conf.name); g_conf.profiler_start(location); - stringstream ss; - ss << g_conf.name << " started profiler with output " << location; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " started profiler with output " + << location << "\n"; } else if (m->cmd.size() == 1 && m->cmd[0] == "stop_profiler") { g_conf.profiler_stop(); - stringstream ss; - ss << g_conf.name << " stopped profiler"; - logclient.log(LOG_INFO, ss); + clog.info() << g_conf.name << " stopped profiler\n"; } else if (m->cmd.size() > 1 && m->cmd[0] == "debug") { if (m->cmd.size() == 3 && m->cmd[1] == "dump_missing") { const string &file_name(m->cmd[2]); std::ofstream fout(file_name.c_str()); if (!fout.is_open()) { - stringstream ss; - ss << "failed to open file '" << file_name << "'"; - logclient.log(LOG_INFO, ss); + clog.info() << "failed to open file '" << file_name << "'\n"; goto done; } @@ -1927,10 +1918,8 @@ void OSD::handle_command(MMonCommand *m) } else if (m->cmd.size() == 3 && m->cmd[1] == "kick_recovery_wq") { g_conf.osd_recovery_delay_start = atoi(m->cmd[2].c_str()); - stringstream ss; - ss << "kicking recovery queue. set osd_recovery_delay_start to " - << g_conf.osd_recovery_delay_start; - logclient.log(LOG_INFO, ss); + clog.info() << "kicking recovery queue. set osd_recovery_delay_start " + << "to " << g_conf.osd_recovery_delay_start << "\n"; defer_recovery_until = g_clock.now(); defer_recovery_until += g_conf.osd_recovery_delay_start; @@ -2745,9 +2734,8 @@ void OSD::handle_osd_map(MOSDMap *m) do_shutdown = true; // don't call shutdown() while we have everything paused } else if (!osdmap->is_up(whoami) || osdmap->get_addr(whoami) != client_messenger->get_myaddr()) { - stringstream ss; - ss << "map e" << osdmap->get_epoch() << " wrongly marked me down"; - logclient.log(LOG_WARN, ss); + clog.warn() << "map e" << osdmap->get_epoch() + << " wrongly marked me down\n"; state = STATE_BOOTING; up_epoch = 0; @@ -3589,9 +3577,8 @@ void OSD::handle_pg_create(MOSDPGCreate *m) } if (up != acting) { dout(10) << "mkpg " << pgid << " up " << up << " != acting " << acting << dendl; - stringstream ss; - ss << "mkpg " << pgid << " up " << up << " != acting " << acting; - logclient.log(LOG_ERROR, ss); + clog.error() << "mkpg " << pgid << " up " << up << " != acting " + << acting << "\n"; continue; } @@ -3992,10 +3979,8 @@ void OSD::_process_pg_info(epoch_t epoch, int from, // did a snap just get purged? if (info.purged_snaps.size() < pg->info.purged_snaps.size()) { - stringstream ss; - ss << "pg " << pg->info.pgid << " replica got purged_snaps " << info.purged_snaps - << " had " << pg->info.purged_snaps; - logclient.log(LOG_WARN, ss); + clog.warn() << "pg " << pg->info.pgid << " replica got purged_snaps " + << info.purged_snaps << " had " << pg->info.purged_snaps << "\n"; pg->info.purged_snaps = info.purged_snaps; } else { interval_set p = info.purged_snaps; @@ -4751,11 +4736,9 @@ void OSD::handle_misdirected_op(PG *pg, MOSDOp *op) op->put(); } else { dout(7) << *pg << " misdirected op in " << op->get_map_epoch() << dendl; - stringstream ss; - ss << op->get_source_inst() << " misdirected " << op->get_reqid() - << " " << pg->info.pgid << " to osd" << whoami - << " not " << pg->acting; - logclient.log(LOG_WARN, ss); + clog.warn() << op->get_source_inst() << " misdirected " + << op->get_reqid() << " " << pg->info.pgid << " to osd" << whoami + << " not " << pg->acting << "\n"; reply_op_error(op, -ENXIO); } } diff --git a/src/osd/OSD.h b/src/osd/OSD.h index 5961add8e9a63..7bcf8fa3468fa 100644 --- a/src/osd/OSD.h +++ b/src/osd/OSD.h @@ -118,7 +118,7 @@ protected: Cond *map_in_progress_cond; bool map_in_progress; - LogClient logclient; + LogClient clog; int whoami; const char *dev_path, *journal_path; @@ -969,8 +969,6 @@ public: void force_remount(); - LogClient *get_logclient() { return &logclient; } - void init_op_flags(MOSDOp *op); }; diff --git a/src/osd/PG.cc b/src/osd/PG.cc index 91d78eeaace7e..3443109be4aad 100644 --- a/src/osd/PG.cc +++ b/src/osd/PG.cc @@ -2402,9 +2402,8 @@ void PG::read_log(ObjectStore *store) // [repair] in order? if (e.version < last) { dout(0) << "read_log " << pos << " out of order entry " << e << " follows " << last << dendl; - stringstream ss; - ss << info.pgid << " log has out of order entry " << e << " following " << last; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " log has out of order entry " + << e << " following " << last << "\n"; reorder = true; } @@ -2415,9 +2414,8 @@ void PG::read_log(ObjectStore *store) if (last.version == e.version.version) { dout(0) << "read_log got dup " << e.version << " (last was " << last << ", dropping that one)" << dendl; log.log.pop_back(); - stringstream ss; - ss << info.pgid << " read_log got dup " << e.version << " after " << last; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " read_log got dup " + << e.version << " after " << last << "\n"; } uint64_t endpos = ondisklog.tail + p.get_off(); @@ -2428,11 +2426,12 @@ void PG::read_log(ObjectStore *store) // [repair] at end of log? if (!p.end() && e.version == info.last_update) { - stringstream ss; - ss << info.pgid << " log has extra data at " << endpos << "~" << (ondisklog.head-endpos) - << " after " << info.last_update; - osd->get_logclient()->log(LOG_ERROR, ss); - dout(0) << "read_log " << endpos << " *** extra gunk at end of log, adjusting ondisklog.head" << dendl; + osd->clog.error() << info.pgid << " log has extra data at " + << endpos << "~" << (ondisklog.head-endpos) << " after " + << info.last_update << "\n"; + + dout(0) << "read_log " << endpos << " *** extra gunk at end of log, " + << "adjusting ondisklog.head" << dendl; ondisklog.head = endpos; break; } @@ -2547,7 +2546,7 @@ bool PG::check_log_for_corruption(ObjectStore *store) getline(f, filename); blb.write_file(filename.c_str(), 0644); ss << ", saved to " << filename; - osd->logclient.log(LOG_ERROR, ss); + osd->clog.error(ss); } return ok; } @@ -3061,7 +3060,6 @@ void PG::repair_object(ScrubMap::object *po, int bad_peer, int ok_peer) void PG::scrub() { - stringstream ss; ScrubMap scrubmap; int errors = 0, fixed = 0; bool repair = state_test(PG_STATE_REPAIR); @@ -3200,8 +3198,8 @@ void PG::scrub() if (anymissing) { for (unsigned i=0; iobjects.end() || po->poid != p[i]->second.poid) { - ss << info.pgid << " " << mode << " osd" << acting[i] << " missing " << po->poid; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " " << mode << " osd" + << acting[i] << " missing " << po->poid << "\n"; num_missing++; if (repair) @@ -3219,18 +3217,20 @@ void PG::scrub() if (po->size != p[i]->second.size) { dout(0) << "scrub osd" << acting[i] << " " << po->poid << " size " << p[i]->second.size << " != " << po->size << dendl; - ss << info.pgid << " " << mode << " osd" << acting[i] << " " << po->poid - << " size " << p[i]->second.size << " != " << po->size; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " " << mode << " osd" + << acting[i] << " " << po->poid << " size " << p[i]->second.size + << " != " << po->size << "\n"; peerok = ok = false; num_bad++; } if (po->attrs.size() != p[i]->second.attrs.size()) { dout(0) << "scrub osd" << acting[i] << " " << po->poid - << " attr count " << p[i]->second.attrs.size() << " != " << po->attrs.size() << dendl; - ss << info.pgid << " " << mode << " osd" << acting[i] << " " << po->poid - << " attr count " << p[i]->second.attrs.size() << " != " << po->attrs.size(); - osd->get_logclient()->log(LOG_ERROR, ss); + << " attr count " << p[i]->second.attrs.size() << " != " + << po->attrs.size() << dendl; + osd->clog.error() << info.pgid << " " << mode << " osd" + << acting[i] << " " << po->poid + << " attr count " << p[i]->second.attrs.size() + << " != " << po->attrs.size() << "\n"; peerok = ok = false; num_bad++; } @@ -3239,18 +3239,18 @@ void PG::scrub() if (q->second.cmp(p[i]->second.attrs[q->first])) { dout(0) << "scrub osd" << acting[i] << " " << po->poid << " attr " << q->first << " value mismatch" << dendl; - ss << info.pgid << " " << mode << " osd" << acting[i] << " " << po->poid - << " attr " << q->first << " value mismatch"; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " " << mode << " osd" + << acting[i] << " " << po->poid + << " attr " << q->first << " value mismatch\n"; peerok = ok = false; num_bad++; } } else { dout(0) << "scrub osd" << acting[i] << " " << po->poid << " attr " << q->first << " missing" << dendl; - ss << info.pgid << " " << mode << " osd" << acting[i] << " " << po->poid - << " attr " << q->first << " missing"; - osd->get_logclient()->log(LOG_ERROR, ss); + osd->clog.error() << info.pgid << " " << mode << " osd" + << acting[i] << " " << po->poid << " attr " << q->first + << " missing" << "\n"; peerok = ok = false; num_bad++; } @@ -3269,9 +3269,12 @@ void PG::scrub() } if (num_missing || num_bad) { - dout(0) << "scrub " << num_missing << " missing, " << num_bad << " bad objects" << dendl; - ss << info.pgid << " " << mode << " " << num_missing << " missing, " << num_bad << " bad objects"; - osd->get_logclient()->log(LOG_ERROR, ss); + stringstream ss; + ss << info.pgid << " " << mode << " " << num_missing << " missing, " + << num_bad << " bad objects\n"; + *_dout << ss.str(); + _dout->flush(); + osd->clog.error(ss); state_set(PG_STATE_INCONSISTENT); if (repair) state_clear(PG_STATE_CLEAN); @@ -3304,14 +3307,21 @@ void PG::scrub() } */ - ss << info.pgid << " " << mode << " "; - if (errors) - ss << errors << " errors"; - else - ss << "ok"; - if (repair) - ss << ", " << fixed << " fixed"; - osd->get_logclient()->log(errors ? LOG_ERROR:LOG_INFO, ss); + { + stringstream oss; + oss << info.pgid << " " << mode << " "; + if (errors) + oss << errors << " errors"; + else + oss << "ok"; + if (repair) + oss << ", " << fixed << " fixed"; + oss << "\n"; + if (errors) + osd->clog.error(oss); + else + osd->clog.info(oss); + } if (!(errors - fixed) && repair) state_clear(PG_STATE_INCONSISTENT); diff --git a/src/osd/ReplicatedPG.cc b/src/osd/ReplicatedPG.cc index 1efd5f7ff01d5..1755427487add 100644 --- a/src/osd/ReplicatedPG.cc +++ b/src/osd/ReplicatedPG.cc @@ -16,6 +16,7 @@ #include "PGLS.h" #include "common/arch.h" +#include "common/errno.h" #include "common/Logger.h" #include "messages/MOSDOp.h" @@ -3154,14 +3155,10 @@ void ReplicatedPG::sub_op_pull(MOSDSubOp *op) struct stat st; int r = osd->store->stat(coll_t(info.pgid), soid, &st); if (r != 0) { - stringstream ss; - char buf[80]; - ss << op->get_source() << " tried to pull " << soid << " in " << info.pgid - << " but got " << strerror_r(-r, buf, sizeof(buf)); - osd->logclient.log(LOG_ERROR, ss); - + osd->clog.error() << op->get_source() << " tried to pull " << soid + << " in " << info.pgid << " but got " + << cpp_strerror(-r) << "\n"; // FIXME: do something more intelligent.. mark the pg as needing repair? - } else { uint64_t size = st.st_size; @@ -4079,17 +4076,16 @@ int ReplicatedPG::_scrub(ScrubMap& scrubmap, int& errors, int& fixed) << stat.num_kb << "/" << info.stats.num_kb << " kb." << dendl; - stringstream ss; if (stat.num_objects != info.stats.num_objects || stat.num_object_clones != info.stats.num_object_clones || stat.num_bytes != info.stats.num_bytes || stat.num_kb != info.stats.num_kb) { - ss << info.pgid << " " << mode << " stat mismatch, got " + osd->clog.error() << info.pgid << " " << mode + << " stat mismatch, got " << stat.num_objects << "/" << info.stats.num_objects << " objects, " << stat.num_object_clones << "/" << info.stats.num_object_clones << " clones, " << stat.num_bytes << "/" << info.stats.num_bytes << " bytes, " - << stat.num_kb << "/" << info.stats.num_kb << " kb."; - osd->get_logclient()->log(LOG_ERROR, ss); + << stat.num_kb << "/" << info.stats.num_kb << " kb.\n"; errors++; if (repair) { -- 2.39.5