mds: report lagginess at lower debug

To help diagnose laggy daemons with performance tuned debug settings.

Signed-off-by: Patrick Donnelly <pdonnell@redhat.com>
(cherry picked from commit c8aff620c273fd4579b23e1647450b6f00c6bac7)

Conflicts:
	src/mds/Beacon.cc

diff --git a/src/mds/Beacon.cc b/src/mds/Beacon.cc
index 60b0cbe3a698c79a6af32e9d6278fde2ae0ebf3a..f7ad85a457d31d3660080d913aea563da66cde12 100644 (file)
--- a/src/mds/Beacon.cc
+++ b/src/mds/Beacon.cc
@@ -124,8 +124,8 @@ void Beacon::handle_mds_beacon(MMDSBeacon *m)
       last_acked_stamp = seq_stamp[seq];
       utime_t rtt = now - last_acked_stamp;
 
-      dout(10) << "handle_mds_beacon " << ceph_mds_state_name(m->get_state())
-              << " seq " << m->get_seq() << " rtt " << rtt << dendl;
+      dout(5) << "handle_mds_beacon " << ceph_mds_state_name(m->get_state())
+             << " seq " << m->get_seq() << " rtt " << rtt << dendl;
 
       if (was_laggy && rtt < g_conf->mds_beacon_grace) {
        dout(0) << "handle_mds_beacon no longer laggy" << dendl;
@@ -135,7 +135,7 @@ void Beacon::handle_mds_beacon(MMDSBeacon *m)
     } else {
       // Mark myself laggy if system clock goes backwards. Hopping
       // later beacons will clear it.
-      dout(1) << "handle_mds_beacon system clock goes backwards, "
+      dout(0) << "handle_mds_beacon system clock goes backwards, "
              << "mark myself laggy" << dendl;
       last_acked_stamp = now - utime_t(g_conf->mds_beacon_grace + 1, 0);
       was_laggy = true;
@@ -151,8 +151,8 @@ void Beacon::handle_mds_beacon(MMDSBeacon *m)
       waiting_cond.Signal();
     }
   } else {
-    dout(10) << "handle_mds_beacon " << ceph_mds_state_name(m->get_state())
-            << " seq " << m->get_seq() << " dne" << dendl;
+    dout(1) << "handle_mds_beacon " << ceph_mds_state_name(m->get_state())
+           << " seq " << m->get_seq() << " dne" << dendl;
   }
   m->put();
 }
@@ -203,14 +203,12 @@ void Beacon::_send()
   if (!cct->get_heartbeat_map()->is_healthy()) {
     /* If anything isn't progressing, let avoid sending a beacon so that
      * the MDS will consider us laggy */
-    dout(1) << __func__ << " skipping beacon, heartbeat map not healthy" << dendl;
+    dout(0) << __func__ << " skipping beacon, heartbeat map not healthy" << dendl;
     return;
   }
 
   ++last_seq;
-  dout(10) << __func__ << " " << ceph_mds_state_name(want_state)
-          << " seq " << last_seq
-          << dendl;
+  dout(5) << __func__ << " " << ceph_mds_state_name(want_state) << " seq " << last_seq << dendl;
 
   seq_stamp[last_seq] = ceph_clock_now();
 
@@ -274,13 +272,13 @@ bool Beacon::is_laggy()
   utime_t now = ceph_clock_now();
   utime_t since = now - last_acked_stamp;
   if (since > g_conf->mds_beacon_grace) {
-    dout(5) << "is_laggy " << since << " > " << g_conf->mds_beacon_grace
+    dout(1) << "is_laggy " << since << " > " << g_conf->mds_beacon_grace
            << " since last acked beacon" << dendl;
     was_laggy = true;
     if (since > (g_conf->mds_beacon_grace*2) &&
        now > last_mon_reconnect + g_conf->mds_beacon_interval) {
       // maybe it's not us?
-      dout(5) << "initiating monitor reconnect; maybe we're not the slow one"
+      dout(1) << "initiating monitor reconnect; maybe we're not the slow one"
               << dendl;
       last_mon_reconnect = now;
       monc->reopen_session();
@@ -309,7 +307,7 @@ void Beacon::set_want_state(MDSMap const *mdsmap, MDSMap::DaemonState const news
   _notify_mdsmap(mdsmap);
 
   if (want_state != newstate) {
-    dout(10) << __func__ << ": "
+    dout(5) << __func__ << ": "
       << ceph_mds_state_name(want_state) << " -> "
       << ceph_mds_state_name(newstate) << dendl;
     want_state = newstate;

diff --git a/src/mds/MDSRank.cc b/src/mds/MDSRank.cc
index 51fedf7264957285ed911ee93c06cd936a152ed4..885895aa63f307654aa6028de458294701a3cea8 100644 (file)
--- a/src/mds/MDSRank.cc
+++ b/src/mds/MDSRank.cc
@@ -246,7 +246,7 @@ void MDSRankDispatcher::tick()
   heartbeat_reset();
 
   if (beacon.is_laggy()) {
-    dout(5) << "tick bailing out since we seem laggy" << dendl;
+    dout(1) << "skipping upkeep work because connection to Monitors appears laggy" << dendl;
     return;
   }
 
@@ -539,10 +539,10 @@ bool MDSRank::_dispatch(Message *m, bool new_msg)
   }
 
   if (beacon.is_laggy()) {
-    dout(10) << " laggy, deferring " << *m << dendl;
+    dout(5) << " laggy, deferring " << *m << dendl;
     waiting_for_nolaggy.push_back(m);
   } else if (new_msg && !waiting_for_nolaggy.empty()) {
-    dout(10) << " there are deferred messages, deferring " << *m << dendl;
+    dout(5) << " there are deferred messages, deferring " << *m << dendl;
     waiting_for_nolaggy.push_back(m);
   } else {
     if (!handle_deferrable_message(m)) {