cluster/afr: Improvement in logging of self heal completion status

Additional information for source and sinks are added.

Change-Id: I1704956ff86ac3ae36744efe7499c1d1c43faeaf
BUG: 968301
Signed-off-by: Venkatesh Somyajulu <vsomyaju@redhat.com>
Reviewed-on: http://review.gluster.org/5638
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Anand Avati <avati@redhat.com>

6 files changed, 338 insertions, 30 deletions

diff --git a/xlators/cluster/afr/src/afr-common.c b/xlators/cluster/afr/src/afr-common.c
index 840025e793c..37a782b312e 100644
--- a/xlators/cluster/afr/src/afr-common.c
+++ b/xlators/cluster/afr/src/afr-common.c
@@ -782,6 +782,9 @@ afr_local_sh_cleanup (afr_local_t *local, xlator_t *this)
         if (sh->data_sh_info && strcmp (sh->data_sh_info, ""))
                 GF_FREE (sh->data_sh_info);
 
+        if (sh->metadata_sh_info && strcmp (sh->metadata_sh_info, ""))
+                GF_FREE (sh->metadata_sh_info);
+
         GF_FREE (sh->buf);
 
         GF_FREE (sh->parentbufs);
diff --git a/xlators/cluster/afr/src/afr-self-heal-common.c b/xlators/cluster/afr/src/afr-self-heal-common.c
index e6a8092316e..f82ce23737e 100644
--- a/xlators/cluster/afr/src/afr-self-heal-common.c
+++ b/xlators/cluster/afr/src/afr-self-heal-common.c
@@ -18,12 +18,24 @@
 #include "afr-self-heal.h"
 #include "pump.h"
 
-#define ADD_FMT_STRING(msg, off, sh_str, status)                            \
+#define ADD_FMT_STRING(msg, off, sh_str, status, print_log)                 \
         do {                                                                \
                 if (AFR_SELF_HEAL_NOT_ATTEMPTED != status) {                \
                         off += snprintf (msg + off, sizeof (msg) - off,     \
                                          " "sh_str" self heal %s,",         \
                                          get_sh_completion_status (status));\
+                        print_log = 1;                                      \
+                }                                                           \
+        } while (0)
+
+#define ADD_FMT_STRING_SYNC(msg, off, sh_str, status, print_log)            \
+        do {                                                                \
+                if (AFR_SELF_HEAL_SYNC_BEGIN == status ||                   \
+                    AFR_SELF_HEAL_FAILED == status)  {                      \
+                        off += snprintf (msg + off, sizeof (msg) - off,     \
+                                         " "sh_str" self heal %s,",         \
+                                         get_sh_completion_status (status));\
+                        print_log = 1;                                      \
                 }                                                           \
         } while (0)
 
@@ -2197,6 +2209,7 @@ afr_self_heal_local_init (afr_local_t *l, xlator_t *this)
         shc->background = sh->background;
         shc->type = sh->type;
         shc->data_sh_info = "";
+        shc->metadata_sh_info =  "";
 
         uuid_copy (shc->sh_gfid_req, sh->sh_gfid_req);
         if (l->loc.path) {
@@ -2716,7 +2729,8 @@ get_sh_completion_status (afr_self_heal_status status)
 
         char *not_attempted       = " is not attempted";
         char *failed              = " failed";
-        char *successfull_complt  = " is successfully completed";
+        char *started             = " is started";
+        char *sync_begin          = " is successfully completed";
         char *result              = " has unknown status";
 
         switch (status)
@@ -2728,7 +2742,10 @@ get_sh_completion_status (afr_self_heal_status status)
                         result = failed;
                         break;
                 case AFR_SELF_HEAL_STARTED:
-                        result = successfull_complt;
+                        result = started;
+                        break;
+                case AFR_SELF_HEAL_SYNC_BEGIN:
+                        result = sync_begin;
                         break;
         }
 
@@ -2745,26 +2762,38 @@ afr_log_self_heal_completion_status (afr_local_t *local, gf_loglevel_t loglvl)
         afr_sh_status_for_all_type   all_status = sh->afr_all_sh_status;
         xlator_t      *this            = NULL;
         size_t        off              = 0;
+        int           data_sh          = 0;
+        int           metadata_sh      = 0;
+        int           print_log        = 0;
 
         this = THIS;
 
         ADD_FMT_STRING (sh_log, off, "gfid or missing entry",
-                        all_status.gfid_or_missing_entry_self_heal);
-        ADD_FMT_STRING (sh_log, off, "metadata", all_status.metadata_self_heal);
+                        all_status.gfid_or_missing_entry_self_heal, print_log);
+        ADD_FMT_STRING_SYNC (sh_log, off, "metadata",
+                             all_status.metadata_self_heal, print_log);
         if (sh->background) {
-                ADD_FMT_STRING (sh_log, off, "backgroung data",
-                                all_status.data_self_heal);
+                ADD_FMT_STRING_SYNC (sh_log, off, "backgroung data",
+                                all_status.data_self_heal, print_log);
         } else {
-                ADD_FMT_STRING (sh_log, off, "foreground data",
-                                all_status.data_self_heal);
+                ADD_FMT_STRING_SYNC (sh_log, off, "foreground data",
+                                all_status.data_self_heal, print_log);
         }
-        ADD_FMT_STRING (sh_log, off, "entry", all_status.entry_self_heal);
+        ADD_FMT_STRING_SYNC (sh_log, off, "entry", all_status.entry_self_heal,
+                             print_log);
 
-        if (AFR_SELF_HEAL_STARTED == all_status.data_self_heal) {
-                gf_log (this->name, loglvl, "%s %s on %s", sh_log,
-                        sh->data_sh_info, local->loc.path);
-        } else {
-                gf_log (this->name, loglvl, "%s on %s", sh_log,
-                        local->loc.path);
-        }
+        if (AFR_SELF_HEAL_SYNC_BEGIN == all_status.data_self_heal &&
+	    strcmp (sh->data_sh_info, "") && sh->data_sh_info )
+                data_sh = 1;
+        if (AFR_SELF_HEAL_SYNC_BEGIN == all_status.metadata_self_heal &&
+	    strcmp (sh->metadata_sh_info, "") && sh->metadata_sh_info)
+                metadata_sh = 1;
+
+        if (!print_log)
+                return;
+
+        gf_log (this->name, loglvl, "%s %s %s on %s", sh_log,
+                ((data_sh == 1) ? sh->data_sh_info : ""),
+                ((metadata_sh == 1) ? sh->metadata_sh_info : ""),
+                local->loc.path);
 }
diff --git a/xlators/cluster/afr/src/afr-self-heal-data.c b/xlators/cluster/afr/src/afr-self-heal-data.c
index cab848832a2..9de26ee569c 100644
--- a/xlators/cluster/afr/src/afr-self-heal-data.c
+++ b/xlators/cluster/afr/src/afr-self-heal-data.c
@@ -728,39 +728,170 @@ out:
 }
 
 char*
-afr_get_sizes_str (struct iatt *bufs, xlator_t *this)
+afr_get_sizes_str (afr_local_t *local, struct iatt *bufs, xlator_t *this)
 {
         afr_private_t *priv = NULL;
         int           i     = 0;
-        char          num[128] = {0};
+        char          num[1024] = {0};
         size_t        len = 0;
         char          *sizes_str = NULL;
         size_t        off = 0;
-        char          *fmt_str = "%llu ";
+        char          *fmt_str = "%llu bytes on %s, ";
+        char          *child_down =  " %s,";
+        char          *child_unknown = " %s,";
+        int           down_child_present = 0;
+        int           down_count = 0;
+        int           unknown_count = 0;
+        int           unknown_child_present = 0;
+        char          *down_subvol_1 = " down subvolume is ";
+        char          *unknown_subvol_1 = " unknown subvolume is ";
+        char          *down_subvol_2 = " down subvolumes are ";
+        char          *unknown_subvol_2 = " unknown subvolumes are ";
 
         priv = this->private;
+
         for (i = 0; i < priv->child_count; i++) {
-                len += snprintf (num, sizeof (num), fmt_str,
-                                 (unsigned long long) bufs[i].ia_size);
+                if (local->child_up[i] == 1) {
+                        len += snprintf (num, sizeof (num), fmt_str,
+                                         (unsigned long long) bufs[i].ia_size,
+                                         priv->children[i]->name);
+                } else if (local->child_up[i] == 0) {
+                        len += snprintf (num, sizeof (num), child_down,
+                                         priv->children[i]->name);
+                        if (!down_child_present)
+                                down_child_present = 1;
+                        down_count ++;
+                } else if (local->child_up[i] == -1) {
+                        len += snprintf (num, sizeof (num), child_unknown,
+                                         priv->children[i]->name);
+                        if (!unknown_child_present)
+                                unknown_child_present = 1;
+                        unknown_count++;
+                }
+
+        }
+
+        if (down_child_present) {
+                if (down_count > 1)
+                        len += snprintf (num, sizeof (num), "%s",
+                                         down_subvol_2);
+                else
+                        len += snprintf (num, sizeof (num), "%s",
+                                        down_subvol_1);
+        }
+        if (unknown_child_present) {
+                if (unknown_count > 1)
+                        len += snprintf (num, sizeof (num), "%s",
+                                         unknown_subvol_2);
+                else
+                        len += snprintf (num, sizeof (num), "%s",
+                                         unknown_subvol_1);
         }
 
         len++;//for '\0'
+
         sizes_str = GF_CALLOC (len, sizeof (char), gf_common_mt_char);
+
         if (!sizes_str)
                 return NULL;
 
         for (i = 0; i < priv->child_count; i++) {
-                off += snprintf (sizes_str + off, len - off, fmt_str,
-                                 (unsigned long long) bufs[i].ia_size);
+                if (local->child_up[i] == 1) {
+                        off += snprintf (sizes_str + off, len - off, fmt_str,
+                                         (unsigned long long) bufs[i].ia_size,
+                                         priv->children[i]->name);
+                }
+        }
+
+        if (down_child_present) {
+                if (down_count > 1) {
+                        off += snprintf (sizes_str + off, len - off, "%s",
+                                         down_subvol_2);
+                } else {
+                        off += snprintf (sizes_str + off, len - off, "%s",
+                                         down_subvol_1);
+                }
+        }
+
+        for (i = 0; i < priv->child_count; i++) {
+                if (local->child_up[i] == 0) {
+                        off += snprintf (sizes_str + off, len - off, child_down,
+                                         priv->children[i]->name);
+                }
+        }
+
+        if (unknown_child_present) {
+                if (unknown_count > 1) {
+                        off += snprintf (sizes_str + off, len - off, "%s",
+                                        unknown_subvol_2);
+                } else {
+                        off += snprintf (sizes_str + off, len - off, "%s",
+                                         unknown_subvol_1);
+                }
+        }
+
+        for (i = 0; i < priv->child_count; i++) {
+                if (local->child_up[i] == -1) {
+                        off += snprintf (sizes_str + off, len - off,
+                                         child_unknown,
+                                         priv->children[i]->name);
+
+                }
         }
+
         return sizes_str;
 }
 
+char*
+afr_get_sinks_str (xlator_t *this, afr_local_t *local, afr_self_heal_t *sh)
+{
+        afr_private_t   *priv = NULL;
+        int             i = 0;
+        char            num[1024] = {0};
+        size_t          len = 0;
+        char            *sinks_str = NULL;
+        char            *temp_str = " to sinks ";
+        char            *str_format = " %s,";
+        char            off = 0;
+
+        priv = this->private;
+
+        len += snprintf (num, sizeof (num), "%s", temp_str);
+        for (i = 0; i < priv->child_count; i++) {
+                if ((sh->sources[i] == 0) && (local->child_up[i] == 1)) {
+                        len += snprintf (num, sizeof (num), str_format,
+                                         priv->children[i]->name);
+                }
+        }
+
+        len ++;
+
+        sinks_str = GF_CALLOC (len, sizeof (char), gf_common_mt_char);
+
+        if (!sinks_str)
+                return NULL;
+
+        off += snprintf (sinks_str + off, len - off, "%s", temp_str);
+
+        for (i = 0; i < priv->child_count; i++) {
+                if ((sh->sources[i] == 0) && (local->child_up[i] == 1)) {
+                        off += snprintf (sinks_str + off, len - off,
+                                         str_format,
+                                         priv->children[i]->name);
+                }
+        }
+
+        return sinks_str;
+
+}
+
+
 void
-afr_set_data_sh_info_str (afr_self_heal_t *sh, xlator_t *this)
+afr_set_data_sh_info_str (afr_local_t *local, afr_self_heal_t *sh, xlator_t *this)
 {
         char            *pending_matrix_str = NULL;
         char            *sizes_str = NULL;
+        char            *sinks_str = NULL;
         afr_private_t   *priv = NULL;
 
         priv = this->private;
@@ -770,13 +901,17 @@ afr_set_data_sh_info_str (afr_self_heal_t *sh, xlator_t *this)
         if (!pending_matrix_str)
                 pending_matrix_str = "";
 
-        sizes_str = afr_get_sizes_str (sh->buf, this);
+        sizes_str = afr_get_sizes_str (local, sh->buf, this);
         if (!sizes_str)
                 sizes_str = "";
 
-        gf_asprintf (&sh->data_sh_info, " from %s with %s sizes %s",
-                     priv->children[sh->source]->name, sizes_str,
-                     pending_matrix_str);
+        sinks_str = afr_get_sinks_str (this, local, sh);
+        if (!sinks_str)
+                sinks_str = "";
+
+        gf_asprintf (&sh->data_sh_info, " data self heal from %s %s with "
+                     "%s data %s", priv->children[sh->source]->name, sinks_str,
+                     sizes_str, pending_matrix_str);
 
         if (pending_matrix_str && strcmp (pending_matrix_str, ""))
                 GF_FREE (pending_matrix_str);
@@ -825,6 +960,7 @@ afr_sh_data_fix (call_frame_t *frame, xlator_t *this)
                 sh->active_sinks);
 
         sh->actual_sh_started = _gf_true;
+        afr_set_self_heal_status (sh, AFR_SELF_HEAL_SYNC_BEGIN);
         afr_sh_data_trim_sinks (frame, this);
 }
 
@@ -905,7 +1041,7 @@ afr_sh_data_fxattrop_fstat_done (call_frame_t *frame, xlator_t *this)
                 }
                 afr_sh_data_setattr (frame, this, &sh->buf[tstamp_source]);
         } else {
-                afr_set_data_sh_info_str (sh, this);
+                afr_set_data_sh_info_str (local, sh, this);
                 if (nsources == 0) {
                         gf_log (this->name, GF_LOG_DEBUG,
                                 "No self-heal needed for %s",
diff --git a/xlators/cluster/afr/src/afr-self-heal-entry.c b/xlators/cluster/afr/src/afr-self-heal-entry.c
index 60d1a5f47f9..53491a1d74c 100644
--- a/xlators/cluster/afr/src/afr-self-heal-entry.c
+++ b/xlators/cluster/afr/src/afr-self-heal-entry.c
@@ -2240,6 +2240,7 @@ afr_sh_entry_sync_prepare (call_frame_t *frame, xlator_t *this)
                         local->loc.path);
 
         sh->actual_sh_started = _gf_true;
+        afr_set_self_heal_status (sh, AFR_SELF_HEAL_SYNC_BEGIN);
         afr_sh_entry_open (frame, this);
 
         return 0;
diff --git a/xlators/cluster/afr/src/afr-self-heal-metadata.c b/xlators/cluster/afr/src/afr-self-heal-metadata.c
index 6d629ce9813..fd5da6cfd33 100644
--- a/xlators/cluster/afr/src/afr-self-heal-metadata.c
+++ b/xlators/cluster/afr/src/afr-self-heal-metadata.c
@@ -406,6 +406,140 @@ afr_sh_metadata_getxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
         return 0;
 }
 
+static void
+afr_set_metadata_sh_info_str (afr_local_t *local, afr_self_heal_t *sh,
+                              xlator_t *this)
+{
+        afr_private_t    *priv = NULL;
+        int              i = 0;
+        char             num[1024] = {0};
+        size_t           len = 0;
+        char             *string = NULL;
+        size_t           off = 0;
+        char             *source_child =  " from source %s to";
+        char             *format = " %s, ";
+        char             *string_msg = " metadata self heal";
+        char             *pending_matrix_str = NULL;
+        int              down_child_present = 0;
+        int              unknown_child_present = 0;
+        char             *down_subvol_1 = " down subvolume is ";
+        char             *unknown_subvol_1 = " unknown subvolume is";
+        char             *down_subvol_2 = " down subvolumes are ";
+        char             *unknown_subvol_2 = " unknown subvolumes are ";
+        int              down_count = 0;
+        int              unknown_count = 0;
+
+        priv = this->private;
+
+        pending_matrix_str = afr_get_pending_matrix_str (sh->pending_matrix,
+                                                         this);
+
+        if (!pending_matrix_str)
+                pending_matrix_str = "";
+
+        len += snprintf (num, sizeof (num), "%s", string_msg);
+
+        for (i = 0; i < priv->child_count; i++) {
+                if ((sh->source == i) && (local->child_up[i] == 1)) {
+                        len += snprintf (num, sizeof (num), source_child,
+                                         priv->children[i]->name);
+                } else if ((local->child_up[i] == 1) && (sh->sources[i] == 0)) {
+                        len += snprintf (num, sizeof (num), format,
+                                         priv->children[i]->name);
+                } else if (local->child_up[i] == 0) {
+                        len += snprintf (num, sizeof (num), format,
+                                         priv->children[i]->name);
+                        if (!down_child_present)
+                                down_child_present = 1;
+                        down_count++;
+                } else if (local->child_up[i] == -1) {
+                        len += snprintf (num, sizeof (num), format,
+                                         priv->children[i]->name);
+                        if (!unknown_child_present)
+                                unknown_child_present = 1;
+                        unknown_count++;
+                }
+        }
+
+        if (down_child_present) {
+                if (down_count > 1) {
+                        len += snprintf (num, sizeof (num), "%s",
+                                         down_subvol_2);
+                } else {
+                        len += snprintf (num, sizeof (num), "%s",
+                                         down_subvol_1);
+                }
+        }
+        if (unknown_child_present) {
+                if (unknown_count > 1) {
+                        len += snprintf (num, sizeof (num), "%s",
+                                         unknown_subvol_2);
+                } else {
+                        len += snprintf (num, sizeof (num), "%s",
+                                         unknown_subvol_1);
+                }
+        }
+
+        len ++;
+
+        string = GF_CALLOC (len, sizeof (char), gf_common_mt_char);
+        if (!string)
+                return;
+
+        off += snprintf (string + off, len - off, "%s", string_msg);
+        for (i=0; i < priv->child_count; i++) {
+                if ((sh->source == i) && (local->child_up[i] == 1))
+                        off += snprintf (string + off, len - off, source_child,
+                                         priv->children[i]->name);
+        }
+
+        for (i = 0; i < priv->child_count; i++) {
+                if ((local->child_up[i] == 1)&& (sh->sources[i] == 0))
+                        off += snprintf (string + off, len - off, format,
+                                         priv->children[i]->name);
+        }
+
+        if (down_child_present) {
+                if (down_count > 1) {
+                        off += snprintf (string + off, len - off, "%s",
+                                         down_subvol_2);
+                } else {
+                        off += snprintf (string + off, len - off, "%s",
+                                         down_subvol_1);
+                }
+        }
+
+        for (i = 0; i < priv->child_count; i++) {
+                if (local->child_up[i] == 0)
+                        off += snprintf (string + off, len - off, format,
+                                         priv->children[i]->name);
+        }
+
+        if (unknown_child_present) {
+                if (unknown_count > 1) {
+                        off += snprintf (string + off, len - off, "%s",
+                                 unknown_subvol_2);
+                } else {
+                        off += snprintf (string + off, len - off, "%s",
+                                         unknown_subvol_1);
+                }
+        }
+
+        for (i = 0; i < priv->child_count; i++) {
+                if (local->child_up[i] == -1)
+                        off += snprintf (string + off, len - off, format,
+                                         priv->children[i]->name);
+        }
+
+        gf_asprintf (&sh->metadata_sh_info, "%s metadata %s,", string,
+                     pending_matrix_str);
+
+        if (pending_matrix_str && strcmp (pending_matrix_str, ""))
+                GF_FREE (pending_matrix_str);
+
+        if (string && strcmp (string, ""))
+                GF_FREE (string);
+}
 
 int
 afr_sh_metadata_sync_prepare (call_frame_t *frame, xlator_t *this)
@@ -436,6 +570,8 @@ afr_sh_metadata_sync_prepare (call_frame_t *frame, xlator_t *this)
                 sh->active_sinks);
 
         sh->actual_sh_started = _gf_true;
+        afr_set_self_heal_status (sh, AFR_SELF_HEAL_SYNC_BEGIN);
+        afr_set_metadata_sh_info_str (local, sh, this);
         STACK_WIND (frame, afr_sh_metadata_getxattr_cbk,
                     priv->children[source],
                     priv->children[source]->fops->getxattr,
diff --git a/xlators/cluster/afr/src/afr.h b/xlators/cluster/afr/src/afr.h
index 2023613f834..70c5a96a7e7 100644
--- a/xlators/cluster/afr/src/afr.h
+++ b/xlators/cluster/afr/src/afr.h
@@ -180,6 +180,7 @@ typedef enum {
         AFR_SELF_HEAL_NOT_ATTEMPTED,
         AFR_SELF_HEAL_STARTED,
         AFR_SELF_HEAL_FAILED,
+        AFR_SELF_HEAL_SYNC_BEGIN,
 } afr_self_heal_status;
 
 typedef struct {
@@ -294,6 +295,8 @@ struct afr_self_heal_ {
         afr_post_remove_call_t post_remove_call;
 
         char    *data_sh_info;
+        char    *metadata_sh_info;
+
         loc_t parent_loc;
         call_frame_t *orig_frame;
         call_frame_t *old_loop_frame;