From c9eb2793e6074521d161632e20954295527d3653 Mon Sep 17 00:00:00 2001 From: John Spray Date: Wed, 8 Nov 2017 11:53:45 -0500 Subject: [PATCH 1/2] mon: monmap log on active should be debug This isn't even a change to the map, just something that got echoed every time a new mon was the leader. Signed-off-by: John Spray --- src/mon/MonmapMonitor.cc | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/mon/MonmapMonitor.cc b/src/mon/MonmapMonitor.cc index f49edccab1b..fae36d6177f 100644 --- a/src/mon/MonmapMonitor.cc +++ b/src/mon/MonmapMonitor.cc @@ -188,8 +188,9 @@ void MonmapMonitor::on_active() mon->has_ever_joined = true; } - if (mon->is_leader()) - mon->clog->info() << "monmap " << *mon->monmap; + if (mon->is_leader()) { + mon->clog->debug() << "monmap " << *mon->monmap; + } apply_mon_features(mon->get_quorum_mon_features()); } From 294fe62feeb155e1ec06d508d92435de98cce90a Mon Sep 17 00:00:00 2001 From: John Spray Date: Wed, 8 Nov 2017 11:54:44 -0500 Subject: [PATCH 2/2] mon: clean up cluster logging on mon events These changes come from observing the output when killing a mon and watching the survivors form a new quorum. Fixes: http://tracker.ceph.com/issues/22082 Signed-off-by: John Spray --- src/mon/Monitor.cc | 31 +++++++++++++++++++++++++------ src/mon/Monitor.h | 4 ++-- 2 files changed, 27 insertions(+), 8 deletions(-) diff --git a/src/mon/Monitor.cc b/src/mon/Monitor.cc index 41b19bb6a78..ac8339a77d5 100644 --- a/src/mon/Monitor.cc +++ b/src/mon/Monitor.cc @@ -1850,7 +1850,7 @@ void Monitor::start_election() logger->inc(l_mon_num_elections); logger->inc(l_mon_election_call); - clog->info() << "mon." << name << " calling new monitor election"; + clog->info() << "mon." << name << " calling monitor election"; elector.call_election(); } @@ -1918,8 +1918,8 @@ void Monitor::win_election(epoch_t epoch, set& active, uint64_t features, pending_metadata = metadata; outside_quorum.clear(); - clog->info() << "mon." << name << "@" << rank - << " won leader election with quorum " << quorum; + clog->info() << "mon." << name << " is new leader, mons " << get_quorum_names() + << " in quorum (ranks " << quorum << ")"; set_leader_commands(get_local_commands(mon_features)); @@ -1960,7 +1960,25 @@ void Monitor::win_election(epoch_t epoch, set& active, uint64_t features, monmap->get_epoch() > 0) { timecheck_start(); health_tick_start(); - do_health_to_clog_interval(); + + // Freshen the health status before doing health_to_clog in case + // our just-completed election changed the health + healthmon()->wait_for_active_ctx(new FunctionContext([this](int r){ + dout(20) << "healthmon now active" << dendl; + healthmon()->tick(); + if (healthmon()->is_proposing()) { + dout(20) << __func__ << " healthmon proposing, waiting" << dendl; + healthmon()->wait_for_finished_proposal(nullptr, new C_MonContext(this, + [this](int r){ + assert(lock.is_locked_by_me()); + do_health_to_clog_interval(); + })); + + } else { + do_health_to_clog_interval(); + } + })); + scrub_event_start(); } } @@ -2287,7 +2305,6 @@ void Monitor::health_tick_start() new C_MonContext(this, [this](int r) { if (r < 0) return; - do_health_to_clog(); health_tick_start(); })); } @@ -4611,7 +4628,9 @@ void Monitor::handle_timecheck_leader(MonOpRequestRef op) ostringstream ss; health_status_t status = timecheck_status(ss, skew_bound, latency); - clog->health(status) << other << " " << ss.str(); + if (status != HEALTH_OK) { + clog->health(status) << other << " " << ss.str(); + } dout(10) << __func__ << " from " << other << " ts " << m->timestamp << " delta " << delta << " skew_bound " << skew_bound diff --git a/src/mon/Monitor.h b/src/mon/Monitor.h index 6b3307f0d3b..4d0ea79637e 100644 --- a/src/mon/Monitor.h +++ b/src/mon/Monitor.h @@ -635,8 +635,8 @@ public: return (class MgrStatMonitor*) paxos_service[PAXOS_MGRSTAT]; } - class MgrStatMonitor *healthmon() { - return (class MgrStatMonitor*) paxos_service[PAXOS_MGRSTAT]; + class HealthMonitor *healthmon() { + return (class HealthMonitor*) paxos_service[PAXOS_HEALTH]; } friend class Paxos;