gsyncd: geo-rep: Reduce excessive verbosity in loggingv3.2.6qa5

Backport logging enhancement from master. This patch
reduces per-second logging to per-minute logging during
crawl

Change-Id: Ie51207e6dd8a0257e59f90239cc6960803673223
BUG: 789078
Signed-off-by: Venky Shankar <vshankar@redhat.com>
Reviewed-on: http://review.gluster.com/2879
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Vijay Bellur <vijay@gluster.com>

1 files changed, 23 insertions, 8 deletions

diff --git a/xlators/features/marker/utils/syncdaemon/master.py b/xlators/features/marker/utils/syncdaemon/master.py
index 35dc4ee06..fca6fc733 100644
--- a/xlators/features/marker/utils/syncdaemon/master.py
+++ b/xlators/features/marker/utils/syncdaemon/master.py
@@ -73,7 +73,9 @@ class GMaster(object):
         self.slave = slave
         self.jobtab = {}
         self.syncer = Syncer(slave)
+        self.crawls = 0
         self.total_turns = int(gconf.turns)
+        self.lastreport = {'crawls': 0, 'turns': 0}
         self.turns = 0
         self.start = None
         self.change_seen = None
@@ -109,6 +111,7 @@ class GMaster(object):
                     time.sleep(gap)
             t = Thread(target=keep_alive)
             t.start()
+        self.lastreport['time'] = time.time()
         while not self.terminate:
             self.crawl()
 
@@ -167,9 +170,19 @@ class GMaster(object):
     def crawl(self, path='.', xtl=None):
         if path == '.':
             if self.start:
-                logging.info("... done, took %.6f seconds" % (time.time() - self.start))
+                self.crawls += 1
+                logging.debug("... crawl #%d done, took %.6f seconds" % \
+                             (self.crawls, (time.time() - self.start)))
             time.sleep(1)
             self.start = time.time()
+            should_display_info = self.start - self.lastreport['time'] >= 60
+            if should_display_info:
+                logging.info("completed %d crawls, %d turns",
+                             self.crawls - self.lastreport['crawls'],
+                             self.turns - self.lastreport['turns'])
+                self.lastreport.update(crawls = self.crawls,
+                                       turns = self.turns,
+                                       time = self.start)
             volinfo_sys = self.get_sys_volinfo()
             self.volinfo_state, state_change = self.volinfo_state_machine(self.volinfo_state,
                                                                           volinfo_sys)
@@ -184,14 +197,16 @@ class GMaster(object):
             if self.volinfo:
                 if self.volinfo['retval']:
                     raise RuntimeError ("master is corrupt")
-                logging.info("%s master with volume id %s ..." % \
-                             (self.inter_master and "intermediate" or "primary", self.uuid))
+                if should_display_info or self.crawls == 0:
+                    logging.info("%s master with volume id %s ..." % \
+                                (self.inter_master and "intermediate" or "primary", self.uuid))
             else:
-                if self.inter_master:
-                    logging.info("waiting for being synced from %s ..." % \
-                                 self.volinfo_state[self.KFGN]['uuid'])
-                else:
-                    logging.info("waiting for volume info ...")
+                if should_display_info or self.crawls == 0:
+                    if self.inter_master:
+                        logging.info("waiting for being synced from %s ..." % \
+                                         self.volinfo_state[self.KFGN]['uuid'])
+                    else:
+                        logging.info("waiting for volume info ...")
                 return
         logging.debug("entering " + path)
         if not xtl: