dht/cluster: add logs to fix-layout code path

Currently there is no helpful log in fix-layout code path. Adding
the logs to be helpful for debugging fix-layout failures.

BUG: 1414782
Change-Id: I61c29ceedcaa2e235fa7be99866709d6ca6de3ae
Signed-off-by: Susant Palai <spalai@redhat.com>
Reviewed-on: http://review.gluster.org/16040
Smoke: Gluster Build System <jenkins@build.gluster.org>
NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
CentOS-regression: Gluster Build System <jenkins@build.gluster.org>
Reviewed-by: Raghavendra G <rgowdapp@redhat.com>

3 files changed, 158 insertions, 49 deletions

diff --git a/xlators/cluster/dht/src/dht-helper.c b/xlators/cluster/dht/src/dht-helper.c
index 81d1dffa0af..002e92b68d7 100644
--- a/xlators/cluster/dht/src/dht-helper.c
+++ b/xlators/cluster/dht/src/dht-helper.c
@@ -2057,9 +2057,10 @@ int32_t
 dht_blocking_inodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                           int32_t op_ret, int32_t op_errno, dict_t *xdata)
 {
-        int          lk_index = 0;
-        int          i        = 0;
-        dht_local_t *local    = NULL;
+        int          lk_index                   = 0;
+        int          i                          = 0;
+        dht_local_t *local                      = NULL;
+        char         gfid[GF_UUID_BUF_SIZE]     = {0,};
 
         lk_index = (long) cookie;
 
@@ -2071,14 +2072,25 @@ dht_blocking_inodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                 case ESTALE:
                 case ENOENT:
                         if (local->lock.reaction != IGNORE_ENOENT_ESTALE) {
+                                gf_uuid_unparse (local->lock.locks[lk_index]->loc.gfid, gfid);
                                 local->lock.op_ret = -1;
                                 local->lock.op_errno = op_errno;
+                                gf_msg (this->name, GF_LOG_ERROR, op_errno,
+                                        DHT_MSG_INODELK_FAILED,
+                                        "inodelk failed on subvol %s. gfid:%s",
+                                        local->lock.locks[lk_index]->xl->name,
+                                        gfid);
                                 goto cleanup;
                         }
                         break;
                 default:
+                        gf_uuid_unparse (local->lock.locks[lk_index]->loc.gfid, gfid);
                         local->lock.op_ret = -1;
                         local->lock.op_errno = op_errno;
+                        gf_msg (this->name, GF_LOG_ERROR, op_errno,
+                                DHT_MSG_INODELK_FAILED,
+                                "inodelk failed on subvol %s, gfid:%s",
+                                local->lock.locks[lk_index]->xl->name, gfid);
                         goto cleanup;
                 }
         }
@@ -2169,20 +2181,35 @@ dht_blocking_inodelk (call_frame_t *frame, dht_lock_t **lk_array,
                       int lk_count, dht_reaction_type_t reaction,
                       fop_inodelk_cbk_t inodelk_cbk)
 {
-        int           ret        = -1;
-        call_frame_t *lock_frame = NULL;
-        dht_local_t  *local      = NULL;
+        int           ret                       = -1;
+        call_frame_t *lock_frame                = NULL;
+        dht_local_t  *local                     = NULL;
+        dht_local_t  *tmp_local                 = NULL;
+        char          gfid[GF_UUID_BUF_SIZE]    = {0,};
 
         GF_VALIDATE_OR_GOTO ("dht-locks", frame, out);
         GF_VALIDATE_OR_GOTO (frame->this->name, lk_array, out);
         GF_VALIDATE_OR_GOTO (frame->this->name, inodelk_cbk, out);
 
+        tmp_local = frame->local;
+
         lock_frame = dht_lock_frame (frame);
-        if (lock_frame == NULL)
+        if (lock_frame == NULL) {
+                gf_uuid_unparse (tmp_local->loc.gfid, gfid);
+                gf_msg ("dht", GF_LOG_ERROR, ENOMEM,
+                        DHT_MSG_LOCK_FRAME_FAILED,
+                        "memory allocation failed for lock_frame. gfid:%s"
+                        " path:%s", gfid, tmp_local->loc.path);
                 goto out;
+        }
 
         ret = dht_local_lock_init (lock_frame, lk_array, lk_count, inodelk_cbk);
         if (ret < 0) {
+                gf_uuid_unparse (tmp_local->loc.gfid, gfid);
+                gf_msg ("dht", GF_LOG_ERROR, ENOMEM,
+                        DHT_MSG_LOCAL_LOCK_INIT_FAILED,
+                        "dht_local_lock_init failed, gfid: %s path:%s", gfid,
+                        tmp_local->loc.path);
                 goto out;
         }
 
diff --git a/xlators/cluster/dht/src/dht-messages.h b/xlators/cluster/dht/src/dht-messages.h
index 30b64eb5711..18859a81912 100644
--- a/xlators/cluster/dht/src/dht-messages.h
+++ b/xlators/cluster/dht/src/dht-messages.h
@@ -40,7 +40,7 @@
  */
 
 #define GLFS_DHT_BASE                   GLFS_MSGID_COMP_DHT
-#define GLFS_DHT_NUM_MESSAGES           118
+#define GLFS_DHT_NUM_MESSAGES           121
 #define GLFS_MSGID_END          (GLFS_DHT_BASE + GLFS_DHT_NUM_MESSAGES + 1)
 
 /* Messages with message IDs */
@@ -1085,5 +1085,26 @@
  */
 #define DHT_MSG_DIR_LOOKUP_FAILED          (GLFS_DHT_BASE + 118)
 
+/*
+ * @messageid 109119
+ * @diagnosis
+ * @recommendedaction None
+ */
+#define DHT_MSG_INODELK_FAILED          (GLFS_DHT_BASE + 119)
+
+/*
+ * @messageid 109120
+ * @diagnosis
+ * @recommendedaction None
+ */
+#define DHT_MSG_LOCK_FRAME_FAILED          (GLFS_DHT_BASE + 120)
+
+/*
+ * @messageid 109121
+ * @diagnosis
+ * @recommendedaction None
+ */
+#define DHT_MSG_LOCAL_LOCK_INIT_FAILED          (GLFS_DHT_BASE + 121)
+
 #define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages"
 #endif /* _DHT_MESSAGES_H_ */
diff --git a/xlators/cluster/dht/src/dht-selfheal.c b/xlators/cluster/dht/src/dht-selfheal.c
index 7fa05a95a53..d6504e881ee 100644
--- a/xlators/cluster/dht/src/dht-selfheal.c
+++ b/xlators/cluster/dht/src/dht-selfheal.c
@@ -172,10 +172,11 @@ dht_refresh_layout_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                         struct iatt *stbuf, dict_t *xattr,
                         struct iatt *postparent)
 {
-        dht_local_t  *local         = NULL;
-        int           this_call_cnt = 0;
-        xlator_t     *prev          = NULL;
-        dht_layout_t *layout        = NULL;
+        dht_local_t  *local                     = NULL;
+        int           this_call_cnt             = 0;
+        xlator_t     *prev                      = NULL;
+        dht_layout_t *layout                    = NULL;
+        char          gfid[GF_UUID_BUF_SIZE]    = {0,};
 
         GF_VALIDATE_OR_GOTO ("dht", frame, err);
         GF_VALIDATE_OR_GOTO ("dht", this, err);
@@ -195,10 +196,12 @@ dht_refresh_layout_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                 dht_iatt_merge (this, &local->stbuf, stbuf, prev);
 
                 if (op_ret == -1) {
+                        gf_uuid_unparse (local->loc.gfid, gfid);
                         local->op_errno = op_errno;
-                        gf_msg_debug (this->name, op_errno,
-                                      "lookup of %s on %s returned error",
-                                      local->loc.path, prev->name);
+                        gf_msg (this->name, GF_LOG_ERROR, op_errno,
+                                DHT_MSG_FILE_LOOKUP_FAILED,
+                                "lookup of %s on %s returned error, gfid: %s",
+                                local->loc.path, prev->name, gfid);
 
                         goto unlock;
                 }
@@ -229,11 +232,12 @@ err:
 int
 dht_refresh_layout (call_frame_t *frame)
 {
-        int          call_cnt = 0;
-        int          i        = 0, ret = -1;
-        dht_conf_t  *conf     = NULL;
-        dht_local_t *local    = NULL;
-        xlator_t    *this     = NULL;
+        int          call_cnt                   = 0;
+        int          i                          = 0, ret = -1;
+        dht_conf_t  *conf                       = NULL;
+        dht_local_t *local                      = NULL;
+        xlator_t    *this                       = NULL;
+        char         gfid[GF_UUID_BUF_SIZE]     = {0,};
 
         GF_VALIDATE_OR_GOTO ("dht", frame, out);
         GF_VALIDATE_OR_GOTO ("dht", frame->local, out);
@@ -254,6 +258,10 @@ dht_refresh_layout (call_frame_t *frame)
         local->selfheal.refreshed_layout = dht_layout_new (this,
                                                            conf->subvolume_cnt);
         if (!local->selfheal.refreshed_layout) {
+                gf_uuid_unparse (local->loc.gfid, gfid);
+                gf_msg (this->name, GF_LOG_ERROR, ENOMEM, DHT_MSG_NO_MEMORY,
+                        "mem allocation for layout failed, path:%s gfid:%s",
+                        local->loc.path, gfid);
                 goto out;
         }
 
@@ -262,8 +270,13 @@ dht_refresh_layout (call_frame_t *frame)
         }
 
         if (local->xattr_req == NULL) {
+                gf_uuid_unparse (local->loc.gfid, gfid);
                 local->xattr_req = dict_new ();
                 if (local->xattr_req == NULL) {
+                        gf_msg (this->name, GF_LOG_ERROR, ENOMEM,
+                                DHT_MSG_NO_MEMORY,
+                                "dict mem allocation failed, path:%s gfid:%s",
+                                local->loc.path, gfid);
                         goto out;
                 }
         }
@@ -532,6 +545,7 @@ dht_selfheal_layout_lock (call_frame_t *frame, dht_layout_t *layout,
         dht_lock_t   **lk_array = NULL;
         dht_conf_t    *conf     = NULL;
         dht_layout_t  *tmp      = NULL;
+        char           gfid[GF_UUID_BUF_SIZE] = {0};
 
         GF_VALIDATE_OR_GOTO ("dht", frame, err);
         GF_VALIDATE_OR_GOTO (frame->this->name, frame->local, err);
@@ -552,29 +566,53 @@ dht_selfheal_layout_lock (call_frame_t *frame, dht_layout_t *layout,
 
                 lk_array = GF_CALLOC (count, sizeof (*lk_array),
                                       gf_common_mt_char);
-                if (lk_array == NULL)
+                if (lk_array == NULL) {
+                        gf_uuid_unparse (local->stbuf.ia_gfid, gfid);
+                        gf_msg ("dht", GF_LOG_ERROR, ENOMEM,
+                                DHT_MSG_NO_MEMORY, "mem allocation failed for "
+                                "lk_array, gfid:%s path: %s", gfid,
+                                local->loc.path);
                         goto err;
+                }
 
                 for (i = 0; i < count; i++) {
                         lk_array[i] = dht_lock_new (frame->this,
                                                     conf->subvolumes[i],
                                                     &local->loc, F_WRLCK,
                                                     DHT_LAYOUT_HEAL_DOMAIN);
-                        if (lk_array[i] == NULL)
+                        if (lk_array[i] == NULL) {
+                                gf_uuid_unparse (local->stbuf.ia_gfid, gfid);
+                                gf_msg (THIS->name, GF_LOG_ERROR, ENOMEM,
+                                        DHT_MSG_NO_MEMORY, "mem allocation "
+                                        "failed for lk_array, gfid:%s path:%s",
+                                        gfid, local->loc.path);
                                 goto err;
+                        }
                 }
         } else {
                 count = 1;
                 lk_array = GF_CALLOC (count, sizeof (*lk_array),
                                       gf_common_mt_char);
-                if (lk_array == NULL)
+                if (lk_array == NULL) {
+                        gf_uuid_unparse (local->stbuf.ia_gfid, gfid);
+                        gf_msg (THIS->name, GF_LOG_ERROR, ENOMEM,
+                                DHT_MSG_NO_MEMORY, "mem allocation failed for "
+                                "lk_array, gfid:%s path:%s",
+                                gfid, local->loc.path);
                         goto err;
+                }
 
                 lk_array[0] = dht_lock_new (frame->this, local->hashed_subvol,
                                             &local->loc, F_WRLCK,
                                             DHT_LAYOUT_HEAL_DOMAIN);
-                if (lk_array[0] == NULL)
+                if (lk_array[0] == NULL) {
+                        gf_uuid_unparse (local->stbuf.ia_gfid, gfid);
+                        gf_msg (THIS->name, GF_LOG_ERROR, ENOMEM,
+                                DHT_MSG_NO_MEMORY, "mem allocation failed for "
+                                "lk_array, gfid:%s path:%s", gfid,
+                                local->loc.path);
                         goto err;
+                }
         }
 
         local->lock.locks = lk_array;
@@ -602,28 +640,37 @@ int
 dht_selfheal_dir_xattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
                             int op_ret, int op_errno, dict_t *xdata)
 {
-        dht_local_t  *local = NULL;
-        xlator_t     *subvol = NULL;
-        struct iatt  *stbuf = NULL;
-        int           i = 0;
-        int           ret = 0;
-        dht_layout_t *layout = NULL;
-        int           err = 0;
-        int           this_call_cnt = 0;
+        dht_local_t  *local                     = NULL;
+        xlator_t     *subvol                    = NULL;
+        struct iatt  *stbuf                     = NULL;
+        int           i                         = 0;
+        int           ret                       = 0;
+        dht_layout_t *layout                    = NULL;
+        int           err                       = 0;
+        int           this_call_cnt             = 0;
+        char          gfid[GF_UUID_BUF_SIZE]    = {0};
 
         local = frame->local;
         layout = local->selfheal.layout;
         subvol = cookie;
 
-        if (op_ret == 0)
+        if (op_ret == 0) {
                 err = 0;
-        else
+        } else {
+                gf_uuid_unparse (local->loc.gfid, gfid);
+                gf_msg (this->name, GF_LOG_ERROR, op_errno,
+                        DHT_MSG_DIR_SELFHEAL_XATTR_FAILED,
+                        "layout setxattr failed on %s, path:%s gfid:%s",
+                        subvol->name, local->loc.path, gfid);
                 err = op_errno;
+        }
 
         ret = dict_get_bin (xdata, DHT_IATT_IN_XDATA_KEY, (void **) &stbuf);
         if (ret < 0) {
-                gf_msg_debug (this->name, 0, "key = %s not present in dict",
-                              DHT_IATT_IN_XDATA_KEY);
+                gf_uuid_unparse (local->loc.gfid, gfid);
+                gf_msg_debug (this->name, 0, "key = %s not present in dict"
+                              ", path:%s gfid:%s", DHT_IATT_IN_XDATA_KEY,
+                              local->loc.path, gfid);
         }
 
         for (i = 0; i < layout->cnt; i++) {
@@ -846,6 +893,7 @@ dht_selfheal_dir_xattr (call_frame_t *frame, loc_t *loc, dht_layout_t *layout)
         xlator_t    *this = NULL;
         dht_conf_t   *conf = NULL;
         dht_layout_t *dummy = NULL;
+        char          gfid[GF_UUID_BUF_SIZE] = {0,};
 
         local = frame->local;
         this = frame->this;
@@ -894,8 +942,13 @@ dht_selfheal_dir_xattr (call_frame_t *frame, loc_t *loc, dht_layout_t *layout)
                         break;
         }
         dummy = dht_layout_new (this, 1);
-        if (!dummy)
+        if (!dummy) {
+                gf_uuid_unparse (loc->gfid, gfid);
+                gf_msg (this->name, GF_LOG_ERROR, ENOMEM, DHT_MSG_NO_MEMORY,
+                        "failed to allocate dummy layout, path:%s gfid:%s",
+                        loc->path, gfid);
                 goto out;
+        }
         for (i = 0; i < conf->subvolume_cnt && missing_xattr; i++) {
                 if (_gf_false ==
                     dht_is_subvol_in_layout (layout, conf->subvolumes[i])) {
@@ -1696,14 +1749,15 @@ dht_layout_t *
 dht_fix_layout_of_directory (call_frame_t *frame, loc_t *loc,
                              dht_layout_t *layout)
 {
-        int           i            = 0;
-        xlator_t     *this         = NULL;
-        dht_layout_t *new_layout   = NULL;
-        dht_conf_t   *priv         = NULL;
-        dht_local_t  *local        = NULL;
-        uint32_t      subvol_down  = 0;
-        int           ret          = 0;
-        gf_boolean_t  maximize_overlap = _gf_true;
+        int           i                         = 0;
+        xlator_t     *this                      = NULL;
+        dht_layout_t *new_layout                = NULL;
+        dht_conf_t   *priv                      = NULL;
+        dht_local_t  *local                     = NULL;
+        uint32_t      subvol_down               = 0;
+        int           ret                       = 0;
+        gf_boolean_t  maximize_overlap          = _gf_true;
+        char          gfid[GF_UUID_BUF_SIZE]    = {0};
 
         this  = frame->this;
         priv  = this->private;
@@ -1716,18 +1770,25 @@ dht_fix_layout_of_directory (call_frame_t *frame, loc_t *loc,
         }
 
         new_layout = dht_layout_new (this, priv->subvolume_cnt);
-        if (!new_layout)
+        if (!new_layout) {
+                gf_uuid_unparse (loc->gfid, gfid);
+                gf_msg (this->name, GF_LOG_ERROR, ENOMEM, DHT_MSG_NO_MEMORY,
+                        "mem allocation failed for new_layout, path:%s gfid:%s",
+                        loc->path, gfid);
                 goto done;
+        }
 
         /* If a subvolume is down, do not re-write the layout. */
         ret = dht_layout_anomalies (this, loc, layout, NULL, NULL, NULL,
                                     &subvol_down, NULL, NULL);
 
         if (subvol_down || (ret == -1)) {
+                gf_uuid_unparse (loc->gfid, gfid);
                 gf_msg (this->name, GF_LOG_WARNING, 0,
                         DHT_MSG_LAYOUT_FIX_FAILED,
                         "Layout fix failed: %u subvolume(s) are down"
-                        ". Skipping fix layout.", subvol_down);
+                        ". Skipping fix layout. path:%s gfid:%s", subvol_down,
+                        loc->path, gfid);
                 GF_FREE (new_layout);
                 return NULL;
         }
@@ -1747,9 +1808,9 @@ dht_fix_layout_of_directory (call_frame_t *frame, loc_t *loc,
                 for (i = 0; i < priv->subvolume_cnt; ++i) {
                         gf_msg (this->name, GF_LOG_DEBUG, 0,
                                 DHT_MSG_SUBVOL_INFO,
-                                "subvolume %d (%s): %u chunks", i,
+                                "subvolume %d (%s): %u chunks, path:%s", i,
                                 priv->subvolumes[i]->name,
-                                priv->du_stats[i].chunks);
+                                priv->du_stats[i].chunks, loc->path);
 
                         /* Maximize overlap if the bricks are all the same
                          *  size.