cluster/afr: Log errors in afr self-heal with GF_LOG_ERROR

Signed-off-by: Pranith Kumar K <pranithk@gluster.com>
Signed-off-by: Anand Avati <avati@gluster.com>

BUG: 2986 (Failed operations should should be logged `E' or `W')
URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=2986

7 files changed, 49 insertions, 44 deletions

diff --git a/xlators/cluster/afr/src/afr-common.c b/xlators/cluster/afr/src/afr-common.c
index 413979e5e..2b073eb9c 100644
--- a/xlators/cluster/afr/src/afr-common.c
+++ b/xlators/cluster/afr/src/afr-common.c
@@ -574,20 +574,20 @@ afr_lookup_collect_xattr (afr_local_t *local, xlator_t *this,
 
         if (afr_sh_has_metadata_pending (xattr, child_index, this)) {
                 local->self_heal.need_metadata_self_heal = _gf_true;
-                gf_log(this->name, GF_LOG_INFO,
+                gf_log(this->name, GF_LOG_DEBUG,
                        "metadata self-heal is pending for %s.",
                        local->loc.path);
         }
 
         if (afr_sh_has_entry_pending (xattr, child_index, this)) {
                 local->self_heal.need_entry_self_heal = _gf_true;
-                gf_log(this->name, GF_LOG_INFO,
+                gf_log(this->name, GF_LOG_DEBUG,
                        "entry self-heal is pending for %s.", local->loc.path);
         }
 
         if (afr_sh_has_data_pending (xattr, child_index, this)) {
                 local->self_heal.need_data_self_heal = _gf_true;
-                gf_log(this->name, GF_LOG_INFO,
+                gf_log(this->name, GF_LOG_DEBUG,
                        "data self-heal is pending for %s.", local->loc.path);
         }
 
diff --git a/xlators/cluster/afr/src/afr-lk-common.c b/xlators/cluster/afr/src/afr-lk-common.c
index 8b214536a..b068b2182 100644
--- a/xlators/cluster/afr/src/afr-lk-common.c
+++ b/xlators/cluster/afr/src/afr-lk-common.c
@@ -563,7 +563,7 @@ afr_unlock_inodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                                op_errno, (long) cookie);
 
         if (op_ret < 0 && op_errno != ENOTCONN && op_errno != EBADFD) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_ERROR,
                         "%s: unlock failed %s",
                         local->loc.path, strerror (op_errno));
         }
diff --git a/xlators/cluster/afr/src/afr-self-heal-algorithm.c b/xlators/cluster/afr/src/afr-self-heal-algorithm.c
index 22791e44d..412d3c6db 100644
--- a/xlators/cluster/afr/src/afr-self-heal-algorithm.c
+++ b/xlators/cluster/afr/src/afr-self-heal-algorithm.c
@@ -158,7 +158,7 @@ sh_full_write_cbk (call_frame_t *rw_frame, void *cookie, xlator_t *this,
         LOCK (&sh_frame->lock);
         {
                 if (op_ret == -1) {
-                        gf_log (this->name, GF_LOG_INFO,
+                        gf_log (this->name, GF_LOG_ERROR,
                                 "write to %s failed on subvolume %s (%s)",
                                 sh_local->loc.path,
                                 priv->children[child_index]->name,
@@ -212,7 +212,7 @@ sh_full_read_cbk (call_frame_t *rw_frame, void *cookie,
                 op_ret, sh_local->loc.path, offset);
 
         if (op_ret <= 0) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_ERROR,
                         "read from %s failed on subvolume %s (%s)",
                         sh_local->loc.path,
                         priv->children[sh->source]->name,
@@ -601,7 +601,7 @@ sh_diff_write_cbk (call_frame_t *rw_frame, void *cookie, xlator_t *this,
         LOCK (&sh_frame->lock);
         {
                 if (op_ret == -1) {
-                        gf_log (this->name, GF_LOG_INFO,
+                        gf_log (this->name, GF_LOG_ERROR,
                                 "write to %s failed on subvolume %s (%s)",
                                 sh_local->loc.path,
                                 priv->children[child_index]->name,
diff --git a/xlators/cluster/afr/src/afr-self-heal-common.c b/xlators/cluster/afr/src/afr-self-heal-common.c
index b64c5fcf6..a0a2b5cf3 100644
--- a/xlators/cluster/afr/src/afr-self-heal-common.c
+++ b/xlators/cluster/afr/src/afr-self-heal-common.c
@@ -780,8 +780,9 @@ afr_sh_missing_entries_done (call_frame_t *frame, xlator_t *this)
 
         if (local->govinda_gOvinda) {
                 gf_log (this->name, GF_LOG_INFO,
-                        "split brain found: aborting selfheal of %s",
+                        "split brain found, aborting selfheal of %s",
                         local->loc.path);
+                sh->op_failed = 1;
                 sh->completion_cbk (frame, this);
         } else {
                 gf_log (this->name, GF_LOG_TRACE,
@@ -1544,11 +1545,16 @@ afr_self_heal_completion_cbk (call_frame_t *bgsh_frame, xlator_t *this)
                                      _gf_false);
         }
 
-        afr_self_heal_type_str_get(sh, sh_type_str,
-                                   sizeof(sh_type_str));
-        gf_log (this->name, GF_LOG_INFO,
-                "background %s self-heal completed on %s", sh_type_str,
-                local->loc.path);
+        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 "
+                        "failed on %s", sh_type_str, local->loc.path);
+        } else {
+                gf_log (this->name, GF_LOG_INFO, "background %s self-heal "
+                        "completed on %s", sh_type_str, local->loc.path);
+        }
+
         FRAME_SU_UNDO (bgsh_frame, afr_local_t);
 
         if (!sh->unwound) {
@@ -1666,7 +1672,7 @@ void
 afr_self_heal_type_str_get (afr_self_heal_t *self_heal_p, char *str,
                             size_t size)
 {
-        GF_ASSERT (str && (size > 0));
+        GF_ASSERT (str && (size > strlen (" meta-data data entry")));
 
         if (self_heal_p->need_metadata_self_heal) {
                 snprintf(str, size, " meta-data");
diff --git a/xlators/cluster/afr/src/afr-self-heal-data.c b/xlators/cluster/afr/src/afr-self-heal-data.c
index 950fcb167..13aa054dc 100644
--- a/xlators/cluster/afr/src/afr-self-heal-data.c
+++ b/xlators/cluster/afr/src/afr-self-heal-data.c
@@ -75,10 +75,6 @@ afr_sh_data_done (call_frame_t *frame, xlator_t *this)
         /* for (i = 0; i < priv->child_count; i++) */
         /*        sh->locked_nodes[i] = 0; */
 
-        gf_log (this->name, GF_LOG_TRACE,
-                "self heal of %s completed",
-                local->loc.path);
-
         sh->completion_cbk (frame, this);
 
         return 0;
@@ -902,18 +898,21 @@ afr_sh_data_post_nonblocking_inodelk_cbk (call_frame_t *frame, xlator_t *this)
 {
         afr_internal_lock_t *int_lock = NULL;
         afr_local_t         *local    = NULL;
+        afr_self_heal_t     *sh       = NULL;
 
         local    = frame->local;
         int_lock = &local->internal_lock;
+        sh       = &local->self_heal;
 
         if (int_lock->lock_op_ret < 0) {
-                gf_log (this->name, GF_LOG_INFO,
-                        "Non Blocking inodelks failed.");
+                gf_log (this->name, GF_LOG_ERROR, "Non Blocking data inodelks "
+                        "failed for %s.", local->loc.path);
+                sh->op_failed = 1;
                 afr_sh_data_done (frame, this);
         } else {
 
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "Non Blocking inodelks done. Proceeding to FOP");
+                gf_log (this->name, GF_LOG_DEBUG, "Non Blocking data inodelks "
+                        "done for %s. Proceeding to FOP", local->loc.path);
                 afr_sh_data_fxattrop (frame, this);
         }
 
@@ -943,7 +942,6 @@ afr_sh_data_lock_rec (call_frame_t *frame, xlator_t *this)
 
         afr_nonblocking_inodelk (frame, this);
 
-
         return 0;
 }
 
@@ -995,7 +993,7 @@ afr_sh_data_open_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,
                                 "open of %s failed on child %s (%s)",
                                 local->loc.path,
                                 priv->children[child_index]->name,
diff --git a/xlators/cluster/afr/src/afr-self-heal-entry.c b/xlators/cluster/afr/src/afr-self-heal-entry.c
index ea2092c67..24f979238 100644
--- a/xlators/cluster/afr/src/afr-self-heal-entry.c
+++ b/xlators/cluster/afr/src/afr-self-heal-entry.c
@@ -75,9 +75,6 @@ afr_sh_entry_done (call_frame_t *frame, xlator_t *this)
         /*        sh->locked_nodes[i] = 0; */
         /* } */
 
-        gf_log (this->name, GF_LOG_TRACE,
-                "self heal of %s completed", local->loc.path);
-
         sh->completion_cbk (frame, this);
 
         return 0;
@@ -1081,7 +1078,7 @@ afr_sh_entry_impunge_newfile_cbk (call_frame_t *impunge_frame, void *cookie,
         child_index = (long) cookie;
 
         if (op_ret == -1) {
-                gf_log (this->name, GF_LOG_INFO,
+                gf_log (this->name, GF_LOG_ERROR,
                         "creation of %s on %s failed (%s)",
                         impunge_local->loc.path,
                         priv->children[child_index]->name,
@@ -1958,7 +1955,7 @@ afr_sh_entry_opendir_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,
                                 "opendir of %s failed on child %s (%s)",
                                 local->loc.path,
                                 priv->children[child_index]->name,
@@ -2258,18 +2255,21 @@ afr_sh_post_nonblocking_entry_cbk (call_frame_t *frame, xlator_t *this)
 {
         afr_internal_lock_t *int_lock = NULL;
         afr_local_t         *local    = NULL;
+        afr_self_heal_t     *sh       = NULL;
 
         local    = frame->local;
         int_lock = &local->internal_lock;
+        sh       = &local->self_heal;
 
         if (int_lock->lock_op_ret < 0) {
-                gf_log (this->name, GF_LOG_INFO,
-                        "Non Blocking entrylks failed.");
+                gf_log (this->name, GF_LOG_ERROR, "Non Blocking entrylks "
+                        "failed for %s.", local->loc.path);
+                sh->op_failed = 1;
                 afr_sh_entry_done (frame, this);
         } else {
 
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "Non Blocking entrylks done. Proceeding to FOP");
+                gf_log (this->name, GF_LOG_DEBUG, "Non Blocking entrylks done "
+                        "for %s. Proceeding to FOP", local->loc.path);
                 afr_sh_entry_lookup(frame, this);
         }
 
diff --git a/xlators/cluster/afr/src/afr-self-heal-metadata.c b/xlators/cluster/afr/src/afr-self-heal-metadata.c
index ee27a7bd1..7ad1ce69a 100644
--- a/xlators/cluster/afr/src/afr-self-heal-metadata.c
+++ b/xlators/cluster/afr/src/afr-self-heal-metadata.c
@@ -77,8 +77,9 @@ afr_sh_metadata_done (call_frame_t *frame, xlator_t *this)
 
         if (local->govinda_gOvinda) {
                 gf_log (this->name, GF_LOG_INFO,
-                        "aborting selfheal of %s",
+                        "split-brain detected, aborting selfheal of %s",
                         local->loc.path);
+                sh->op_failed = 1;
                 sh->completion_cbk (frame, this);
         } else {
                 if (IA_ISREG (sh->type)) {
@@ -96,10 +97,6 @@ afr_sh_metadata_done (call_frame_t *frame, xlator_t *this)
                         afr_self_heal_entry (frame, this);
                         return 0;
                 }
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "completed self heal of %s",
-                        local->loc.path);
-
                 sh->completion_cbk (frame, this);
         }
 
@@ -661,7 +658,8 @@ afr_sh_metadata_lookup (call_frame_t *frame, xlator_t *this)
 }
 
 int
-afr_sh_post_nonblocking_inodelk_cbk (call_frame_t *frame, xlator_t *this)
+afr_sh_metadata_post_nonblocking_inodelk_cbk (call_frame_t *frame,
+                                              xlator_t *this)
 {
         afr_internal_lock_t *int_lock = NULL;
         afr_local_t         *local    = NULL;
@@ -670,13 +668,16 @@ afr_sh_post_nonblocking_inodelk_cbk (call_frame_t *frame, xlator_t *this)
         int_lock = &local->internal_lock;
 
         if (int_lock->lock_op_ret < 0) {
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "Non Blocking inodelks failed.");
+                gf_log (this->name, GF_LOG_ERROR, "Non Blocking metadata "
+                        "inodelks failed for %s.", local->loc.path);
+                gf_log (this->name, GF_LOG_ERROR, "Metadata self-heal "
+                        "failed for %s.", local->loc.path);
                 afr_sh_metadata_done (frame, this);
         } else {
 
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "Non Blocking inodelks done. Proceeding to FOP");
+                gf_log (this->name, GF_LOG_DEBUG, "Non Blocking metadata "
+                        "inodelks done for %s. Proceeding to FOP",
+                        local->loc.path);
                 afr_sh_metadata_lookup (frame, this);
         }
 
@@ -700,7 +701,7 @@ afr_sh_metadata_lock (call_frame_t *frame, xlator_t *this)
         int_lock->lk_flock.l_start = 0;
         int_lock->lk_flock.l_len   = 0;
         int_lock->lk_flock.l_type  = F_WRLCK;
-        int_lock->lock_cbk         = afr_sh_post_nonblocking_inodelk_cbk;
+        int_lock->lock_cbk         = afr_sh_metadata_post_nonblocking_inodelk_cbk;
 
         afr_nonblocking_inodelk (frame, this);