afr: Avoid excessive logging in self-heal.

- (Excessive) Logging has been very useful as 'bread-crumbs' in
  many a root-cause analyses. This patch aims at avoiding logging when
  the information could be reconstructed using the xattrs, statedump,
  and/or "volume heal" CLI commands.

Change-Id: Iebc6b10ae18f0dd9704bdc6dd03bcfe0f2a09abd
BUG: 844804
Signed-off-by: Krishnan Parthasarathi <kparthas@redhat.com>
Reviewed-on: http://review.gluster.org/3805
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Anand Avati <avati@redhat.com>

6 files changed, 25 insertions, 22 deletions

diff --git a/xlators/cluster/afr/src/afr-common.c b/xlators/cluster/afr/src/afr-common.c
index 70a9cd35463..ddcd0bca37a 100644
--- a/xlators/cluster/afr/src/afr-common.c
+++ b/xlators/cluster/afr/src/afr-common.c
@@ -1219,7 +1219,7 @@ afr_detect_self_heal_by_iatt (afr_local_t *local, xlator_t *this,
 {
         if (PERMISSION_DIFFERS (buf, lookup_buf)) {
                 /* mismatching permissions */
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "permissions differ for %s ", local->loc.path);
                 local->self_heal.do_metadata_self_heal = _gf_true;
         }
@@ -1227,13 +1227,13 @@ afr_detect_self_heal_by_iatt (afr_local_t *local, xlator_t *this,
         if (OWNERSHIP_DIFFERS (buf, lookup_buf)) {
                 /* mismatching permissions */
                 local->self_heal.do_metadata_self_heal = _gf_true;
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "ownership differs for %s ", local->loc.path);
         }
 
         if (SIZE_DIFFERS (buf, lookup_buf)
             && IA_ISREG (buf->ia_type)) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "size differs for %s ", local->loc.path);
                 local->self_heal.do_data_self_heal = _gf_true;
         }
@@ -1258,7 +1258,7 @@ afr_detect_self_heal_by_split_brain_status (afr_local_t *local, xlator_t *this)
         if ((local->success_count > 0) && split_brain &&
             IA_ISREG (local->cont.lookup.inode->ia_type)) {
                 sh->force_confirm_spb = _gf_true;
-                gf_log (this->name, GF_LOG_WARNING,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "split brain detected during lookup of %s.",
                         local->loc.path);
         }
@@ -1276,14 +1276,11 @@ afr_detect_self_heal_by_lookup_status (afr_local_t *local, xlator_t *this)
                 local->self_heal.do_entry_self_heal    = _gf_true;
                 local->self_heal.do_gfid_self_heal    = _gf_true;
                 local->self_heal.do_missing_entry_self_heal    = _gf_true;
-                gf_log(this->name, GF_LOG_INFO,
+                gf_log(this->name, GF_LOG_DEBUG,
                        "entries are missing in lookup of %s.",
                        local->loc.path);
-                //If all self-heals are needed no need to check for other rules
-                goto out;
         }
 
-out:
         return;
 }
 
@@ -1396,7 +1393,7 @@ afr_launch_self_heal (call_frame_t *frame, xlator_t *this, inode_t *inode,
 
         if (background)
                 bg = "background";
-        gf_log (this->name, GF_LOG_INFO,
+        gf_log (this->name, GF_LOG_DEBUG,
                 "%s %s self-heal triggered. path: %s, reason: %s", bg,
                 sh_type_str, local->loc.path, reason);
 
diff --git a/xlators/cluster/afr/src/afr-self-heal-algorithm.c b/xlators/cluster/afr/src/afr-self-heal-algorithm.c
index 201e12c523f..9ad40592088 100644
--- a/xlators/cluster/afr/src/afr-self-heal-algorithm.c
+++ b/xlators/cluster/afr/src/afr-self-heal-algorithm.c
@@ -103,7 +103,7 @@ sh_loop_driver_done (call_frame_t *sh_frame, xlator_t *this,
         if (sh->op_failed) {
                 GF_ASSERT (!last_loop_frame);
                 //loop_finish should have happened and the old_loop should be NULL
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "self-heal aborting on %s",
                         local->loc.path);
 
@@ -111,10 +111,10 @@ sh_loop_driver_done (call_frame_t *sh_frame, xlator_t *this,
         } else {
                 GF_ASSERT (last_loop_frame);
                 if (diff_blocks == total_blocks) {
-                        gf_log (this->name, GF_LOG_INFO, "full self-heal "
+                        gf_log (this->name, GF_LOG_DEBUG, "full self-heal "
                                 "completed on %s",local->loc.path);
                 } else {
-                        gf_log (this->name, GF_LOG_INFO,
+                        gf_log (this->name, GF_LOG_DEBUG,
                                 "diff self-heal on %s: completed. "
                                 "(%d blocks of %d were different (%.2f%%))",
                                 local->loc.path, diff_blocks, total_blocks,
diff --git a/xlators/cluster/afr/src/afr-self-heal-common.c b/xlators/cluster/afr/src/afr-self-heal-common.c
index 48fa31d8689..a081904803f 100644
--- a/xlators/cluster/afr/src/afr-self-heal-common.c
+++ b/xlators/cluster/afr/src/afr-self-heal-common.c
@@ -1007,7 +1007,7 @@ afr_sh_missing_entries_done (call_frame_t *frame, xlator_t *this)
         afr_sh_reset (frame, this);
 
         if (local->govinda_gOvinda) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "split brain found, aborting selfheal of %s",
                         local->loc.path);
                 sh->op_failed = 1;
@@ -1099,7 +1099,7 @@ afr_sh_common_lookup_resp_handler (call_frame_t *frame, void *cookie,
                         sh->success_count++;
                         sh->xattr[child_index] = dict_ref (xattr);
                 } else {
-                        gf_log (this->name, GF_LOG_ERROR, "path %s on subvolume"
+                        gf_log (this->name, GF_LOG_DEBUG, "path %s on subvolume"
                                 " %s => -1 (%s)", loc->path,
                                 priv->children[child_index]->name,
                                 strerror (op_errno));
@@ -2171,11 +2171,17 @@ afr_self_heal_completion_cbk (call_frame_t *bgsh_frame, xlator_t *this)
         afr_self_heal_type_str_get (sh, sh_type_str,
                                     sizeof(sh_type_str));
         if (sh->op_failed) {
-                gf_log (this->name, GF_LOG_ERROR, "background %s self-heal "
+                gf_loglevel_t     loglevel = GF_LOG_ERROR;
+                if (priv->shd.iamshd)
+                        loglevel = GF_LOG_DEBUG;
+
+                gf_log (this->name, loglevel, "background %s self-heal "
                         "failed on %s", sh_type_str, local->loc.path);
+
         } else {
-                gf_log (this->name, GF_LOG_INFO, "background %s self-heal "
+                gf_log (this->name, GF_LOG_DEBUG, "background %s self-heal "
                         "completed on %s", sh_type_str, local->loc.path);
+
         }
 
         FRAME_SU_UNDO (bgsh_frame, afr_local_t);
diff --git a/xlators/cluster/afr/src/afr-self-heal-data.c b/xlators/cluster/afr/src/afr-self-heal-data.c
index 6619c1353c7..6501e596c32 100644
--- a/xlators/cluster/afr/src/afr-self-heal-data.c
+++ b/xlators/cluster/afr/src/afr-self-heal-data.c
@@ -91,7 +91,7 @@ afr_sh_data_flush_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
         LOCK (&frame->lock);
         {
                 if (op_ret == -1) {
-                        gf_log (this->name, GF_LOG_INFO,
+                        gf_log (this->name, GF_LOG_ERROR,
                                 "flush failed on %s on subvolume %s: %s",
                                 local->loc.path, priv->children[child_index]->name,
                                 strerror (op_errno));
@@ -775,7 +775,7 @@ afr_lookup_select_read_child_by_txn_type (xlator_t *this, afr_local_t *local,
                                       sources, success_children, txn_type,
                                       &subvol_status, _gf_false);
         if (subvol_status & SPLIT_BRAIN) {
-                gf_log (this->name, GF_LOG_WARNING, "%s: Possible split-brain",
+                gf_log (this->name, GF_LOG_DEBUG, "%s: Possible split-brain",
                         local->loc.path);
                 switch (txn_type) {
                 case AFR_DATA_TRANSACTION:
diff --git a/xlators/cluster/afr/src/afr-self-heal-metadata.c b/xlators/cluster/afr/src/afr-self-heal-metadata.c
index 79ce07d0039..4f81c1cf582 100644
--- a/xlators/cluster/afr/src/afr-self-heal-metadata.c
+++ b/xlators/cluster/afr/src/afr-self-heal-metadata.c
@@ -51,7 +51,7 @@ afr_sh_metadata_done (call_frame_t *frame, xlator_t *this)
 
         afr_sh_reset (frame, this);
         if (sh->mdata_spb) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_DEBUG,
                         "split-brain detected, aborting selfheal of %s",
                         local->loc.path);
                 sh->op_failed = 1;
@@ -472,9 +472,9 @@ afr_sh_metadata_post_nonblocking_inodelk_cbk (call_frame_t *frame,
         int_lock = &local->internal_lock;
 
         if (int_lock->lock_op_ret < 0) {
-                gf_log (this->name, GF_LOG_ERROR, "Non Blocking metadata "
+                gf_log (this->name, GF_LOG_DEBUG, "Non Blocking metadata "
                         "inodelks failed for %s.", local->loc.path);
-                gf_log (this->name, GF_LOG_ERROR, "Metadata self-heal "
+                gf_log (this->name, GF_LOG_DEBUG, "Metadata self-heal "
                         "failed for %s.", local->loc.path);
                 afr_sh_metadata_done (frame, this);
         } else {
diff --git a/xlators/cluster/afr/src/afr-self-heald.c b/xlators/cluster/afr/src/afr-self-heald.c
index 741cf42b5dc..b5653dee73e 100644
--- a/xlators/cluster/afr/src/afr-self-heald.c
+++ b/xlators/cluster/afr/src/afr-self-heald.c
@@ -275,7 +275,7 @@ _remove_stale_index (xlator_t *this, xlator_t *readdir_xl,
         ret = _build_index_loc (this, &index_loc, fname, parent);
         if (ret)
                 goto out;
-        gf_log (this->name, GF_LOG_INFO, "Removing stale index "
+        gf_log (this->name, GF_LOG_DEBUG, "Removing stale index "
                 "for %s on %s", index_loc.name, readdir_xl->name);
         ret = syncop_unlink (readdir_xl, &index_loc);
         if(ret && (errno != ENOENT)) {