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 <john.spray@redhat.com>

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,20 @@ void Monitor::win_election(epoch_t epoch, set<int>& active, uint64_t features,
   pending_metadata = metadata;
   outside_quorum.clear();
 
-  clog->info() << "mon." << name << "@" << rank
-		<< " won leader election with quorum " << quorum;
+  std::stringstream msg;
+  msg << "mon." << name << " is new leader, mons ";
+  for (auto i = quorum.begin(); i != quorum.end();) {
+    derr << "rank: " << *i << dendl;
+    auto q_rank = *i;
+    ++i;
+
+    msg << monmap->get_name(q_rank);
+    if (i != quorum.end()) {
+      msg << ",";
+    }
+  }
+  msg << " in quorum (ranks " << quorum << ")";
+  clog->info() << msg.str();
 
   set_leader_commands(get_local_commands(mon_features));
 
@@ -1960,7 +1972,26 @@ void Monitor::win_election(epoch_t epoch, set<int>& 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(4) << __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 {
+        dout(4) << __func__ << " healthmon is not proposing" << dendl;
+        do_health_to_clog_interval();
+      }
+    }));
+
     scrub_event_start();
   }
 }
@@ -2287,7 +2318,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 +4641,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

src/mon/Monitor.h

@@ -635,8 +635,8 @@ class Monitor : public Dispatcher,
     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;