osd: debug the hell out of heartbeat thread

Signed-off-by: Sage Weil <sage.weil@dreamhost.com>

diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc
index e379a9ba5e733ad32c3779d6ba0ed77eec5e128c..10a78a00a6744cc4cecca5e38830a1ea30e29563 100644 (file)
--- a/src/osd/OSD.cc
+++ b/src/osd/OSD.cc
@@ -1488,7 +1488,9 @@ void OSD::heartbeat_entry()
     double wait = .5 + ((float)(rand() % 10)/10.0) * (float)g_conf.osd_heartbeat_interval;
     utime_t w;
     w.set_from_double(wait);
+    dout(30) << "heartbeat_entry sleeping for " << wait << dendl;
     heartbeat_cond.WaitInterval(heartbeat_lock, w);
+    dout(30) << "heartbeat_entry woke up" << dendl;
   }
   heartbeat_lock.Unlock();
 }
@@ -1519,6 +1521,8 @@ void OSD::heartbeat()
 {
   utime_t now = g_clock.now();
 
+  dout(30) << "heartbeat" << dendl;
+
   if (got_sigterm) {
     derr << "got SIGTERM, shutting down" << dendl;
     Message *m = new MGenericMessage(CEPH_MSG_SHUTDOWN);
@@ -1544,6 +1548,8 @@ void OSD::heartbeat()
     derr << "heartbeat: failed to read /proc/loadavg" << dendl;
   }
 
+  dout(30) << "heartbeat checking stats" << dendl;
+
   // calc my stats
   Mutex::Locker lock(peer_stat_lock);
   _refresh_my_stat(now);
@@ -1555,7 +1561,8 @@ void OSD::heartbeat()
   //load_calc.set_size(stat_ops);
 
   bool map_locked = map_lock.try_get_read();
-  
+  dout(30) << "heartbeat map_locked=" << map_locked << dendl;
+
   // send heartbeats
   for (map<int, epoch_t>::iterator i = heartbeat_to.begin();
        i != heartbeat_to.end();
@@ -1563,23 +1570,30 @@ void OSD::heartbeat()
     int peer = i->first;
     if (heartbeat_inst.count(peer)) {
       my_stat_on_peer[peer] = my_stat;
+      dout(30) << "heartbeat allocating ping for osd" << peer << dendl;
       Message *m = new MOSDPing(osdmap->get_fsid(),
                                map_locked ? osdmap->get_epoch():0, 
                                i->second,
                                my_stat);
       m->set_priority(CEPH_MSG_PRIO_HIGH);
+      dout(30) << "heartbeat sending ping to osd" << peer << dendl;
       heartbeat_messenger->send_message(m, heartbeat_inst[peer]);
     }
   }
 
-  if (map_locked)
+  if (map_locked) {
+    dout(30) << "heartbeat check" << dendl;
     heartbeat_check();
+  } else {
+    dout(30) << "heartbeat no map_lock, no check" << dendl;
+  }
 
   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?
+  dout(30) << "heartbeat lonely?" << dendl;
   if (heartbeat_from.empty() || heartbeat_to.empty()) {
     if (now - last_mon_heartbeat > g_conf.osd_mon_heartbeat_interval) {
       last_mon_heartbeat = now;
@@ -1589,8 +1603,11 @@ void OSD::heartbeat()
     }
   }
 
-  if (map_locked)
+  if (map_locked) {
+    dout(30) << "heartbeat put map_lock" << dendl;
     map_lock.put_read();
+  }
+  dout(30) << "heartbeat done" << dendl;
 }