summaryrefslogtreecommitdiffstats
path: root/xlators
diff options
context:
space:
mode:
authorVenkatesh Somyajulu <vsomyaju@redhat.com>2014-09-05 11:14:44 -0400
committerVijay Bellur <vbellur@redhat.com>2014-09-09 12:20:07 -0700
commitdf31ed49a51670f30d30abb377eb020cc9e85c10 (patch)
tree86c41496a2ad91ed8d66c1328dc700590741eb68 /xlators
parent9aa15dff0867f6ccd8706ea195fcb37f3a882505 (diff)
cluster/dht: Added code to capture races in dht-lookup path
Change-Id: I9270d2d40ebd4b113ff961583dfda7754741f151 BUG: 1138385 Signed-off-by: Venkatesh Somyajulu <vsomyaju@redhat.com> Reviewed-on-master: http://review.gluster.org/8430 Tested-by: Gluster Build System <jenkins@build.gluster.com> Reviewed-by: Vijay Bellur <vbellur@redhat.com> Reviewed-by: Jeff Darcy <jdarcy@redhat.com> Reviewed-on: http://review.gluster.org/8668 Tested-by: Vijay Bellur <vbellur@redhat.com>
Diffstat (limited to 'xlators')
-rw-r--r--xlators/cluster/dht/src/dht-common.c156
-rw-r--r--xlators/storage/posix/src/posix.c6
2 files changed, 152 insertions, 10 deletions
diff --git a/xlators/cluster/dht/src/dht-common.c b/xlators/cluster/dht/src/dht-common.c
index 313fd89aa59..0d686bdbf4a 100644
--- a/xlators/cluster/dht/src/dht-common.c
+++ b/xlators/cluster/dht/src/dht-common.c
@@ -507,10 +507,14 @@ dht_lookup_dir_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
is_dir = check_is_dir (inode, stbuf, xattr);
if (!is_dir) {
+
gf_msg_debug (this->name, 0,
- "lookup of %s on %s returned non dir 0%o",
+ "lookup of %s on %s returned non"
+ "dir 0%o"
+ "calling lookup_everywhere",
local->loc.path, prev->this->name,
stbuf->ia_type);
+
local->need_selfheal = 1;
goto unlock;
}
@@ -610,6 +614,12 @@ dht_revalidate_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
LOCK (&frame->lock);
{
+
+ gf_msg_debug (this->name, 0,
+ "revalidate lookup of %s "
+ "returned with op_ret %d and op_errno %d",
+ local->loc.path, op_ret, op_errno);
+
if (op_ret == -1) {
local->op_errno = op_errno;
@@ -634,6 +644,14 @@ dht_revalidate_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
* the file is not migrated */
if (op_errno == ENOENT) {
if (IA_ISREG (local->loc.inode->ia_type)) {
+
+ gf_msg_debug (this->name, 0,
+ "found ENOENT for %s. "
+ "Setting "
+ "need_lookup_everywhere"
+ " flag to 1",
+ local->loc.path);
+
local->need_lookup_everywhere = 1;
}
}
@@ -839,9 +857,16 @@ dht_lookup_linkfile_create_cbk (call_frame_t *frame, void *cookie,
}
unwind:
+ gf_msg_debug (this->name, 0,
+ "creation of linkto on hashed subvol:%s, "
+ "returned with op_ret %d and op_errno %d: %s",
+ local->hashed_subvol->name,
+ op_ret, op_errno, uuid_utoa (local->loc.gfid));
+
if (local->linked == _gf_true)
dht_linkfile_attr_heal (frame, this);
+
DHT_STRIP_PHASE1_FLAGS (&local->stbuf);
DHT_STACK_UNWIND (lookup, frame, local->op_ret, local->op_errno,
local->inode, &local->stbuf, local->xattr,
@@ -926,12 +951,24 @@ dht_lookup_unlink_stale_linkto_cbk (call_frame_t *frame, void *cookie,
struct iatt *postparent, dict_t *xdata)
{
+ dht_local_t *local = NULL;
+ const char *path = NULL;
+
/* NOTE:
* If stale file unlink fails either there is an open-fd or is not an
* dht-linkto-file then posix_unlink returns EBUSY, which is overwritten
* to ENOENT
*/
+ local = frame->local;
+
+ if (local && local->loc.path)
+ path = local->loc.path;
+
+ gf_log (this->name, GF_LOG_INFO, "Returned with op_ret %d and "
+ "op_errno %d for %s", op_ret, op_errno,
+ ((path==NULL)?"null":path));
+
DHT_STACK_UNWIND (lookup, frame, -1, ENOENT, NULL, NULL, NULL,
NULL);
@@ -1012,6 +1049,10 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
return 0;
}
+ gf_log (this->name, GF_LOG_INFO, "STATUS: hashed_subvol %s "
+ "cached_subvol %s",
+ (hashed_subvol == NULL)?"null":hashed_subvol->name,
+ (cached_subvol == NULL)?"null":cached_subvol->name);
if (!cached_subvol) {
@@ -1064,7 +1105,14 @@ dict_err:
NULL, NULL, NULL, NULL);
} else {
local->skip_unlink.handle_valid_link = _gf_false;
- STACK_WIND (frame,
+
+ gf_msg_debug (this->name, 0,
+ "No Cached was found and "
+ "unlink on hashed was skipped"
+ " so performing now: %s",
+ local->loc.path);
+
+ STACK_WIND (frame,
dht_lookup_unlink_stale_linkto_cbk,
hashed_subvol,
hashed_subvol->fops->unlink,
@@ -1073,6 +1121,11 @@ dict_err:
} else {
+ gf_msg_debug (this->name, 0,
+ "There was no cached file and "
+ "unlink on hashed is not skipped %s",
+ local->loc.path);
+
DHT_STACK_UNWIND (lookup, frame, -1, ENOENT, NULL, NULL,
NULL, NULL);
}
@@ -1096,6 +1149,11 @@ dict_err:
} else if ((local->file_count == 1) &&
(hashed_subvol == cached_subvol)) {
+ gf_msg_debug (this->name, 0,
+ "found cached file on hashed subvolume "
+ "so store in context and return for %s",
+ local->loc.path);
+
found_non_linkto_on_hashed = _gf_true;
}
@@ -1141,10 +1199,29 @@ dict_err:
(local->loc.parent, this,
&local->postparent, 1);
}
+
+ gf_msg_debug (this->name, 0,
+ "Skipped unlinking linkto file "
+ "on the hashed subvolume. "
+ "Returning success as it is a "
+ "valid linkto file. Path:%s"
+ ,local->loc.path);
+
goto unwind_hashed_and_cached;
} else {
local->skip_unlink.handle_valid_link = _gf_false;
+
+ gf_msg_debug (this->name, 0,
+ "Linkto file found on hashed "
+ "subvol "
+ "and data file found on cached "
+ "subvolume. But linkto points to "
+ "different cached subvolume (%s) "
+ "path %s",
+ local->skip_unlink.hash_links_to->name,
+ local->loc.path);
+
if (local->skip_unlink.opend_fd_count == 0) {
@@ -1224,11 +1301,11 @@ preset_layout:
}
if (!hashed_subvol) {
- gf_msg (this->name, GF_LOG_INFO, 0,
- DHT_MSG_HASHED_SUBVOL_GET_FAILED,
- "cannot create linkfile file for %s on %s: "
- "hashed subvolume cannot be found, gfid = %s.",
- local->loc.path, cached_subvol->name, gfid);
+
+ gf_msg_debug (this->name, 0,
+ "Cannot create linkfile for %s on %s: "
+ "hashed subvolume cannot be found, gfid = %s.",
+ local->loc.path, cached_subvol->name, gfid);
local->op_ret = 0;
local->op_errno = 0;
@@ -1309,6 +1386,11 @@ dht_lookup_everywhere_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
prev = cookie;
subvol = prev->this;
+ gf_msg_debug (this->name, 0,
+ "returned with op_ret %d and op_errno %d (%s) "
+ "from subvol %s", op_ret, op_errno, loc->path,
+ subvol->name);
+
LOCK (&frame->lock);
{
if (op_ret == -1) {
@@ -1333,6 +1415,14 @@ dht_lookup_everywhere_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
is_linkfile = check_is_linkfile (inode, buf, xattr,
conf->link_xattr_name);
+
+ if (is_linkfile) {
+
+ gf_msg_debug (this->name, 0,
+ "Found linktofile on %s for %s",
+ subvol->name, loc->path);
+
+ }
is_dir = check_is_dir (inode, buf, xattr);
if (is_linkfile) {
@@ -1357,15 +1447,20 @@ dht_lookup_everywhere_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
} else {
local->file_count++;
+ gf_msg_debug (this->name, 0,
+ "found cached file on %s for %s",
+ subvol->name, loc->path);
+
if (!local->cached_subvol) {
/* found one file */
dht_iatt_merge (this, &local->stbuf, buf,
subvol);
local->xattr = dict_ref (xattr);
local->cached_subvol = subvol;
+
gf_msg_debug (this->name, 0,
- "found on %s file %s",
- subvol->name, loc->path);
+ "storing cached on %s file"
+ " %s", subvol->name, loc->path);
dht_iatt_merge (this, &local->postparent,
postparent, subvol);
@@ -1409,6 +1504,12 @@ unlock:
uuid_copy (local->skip_unlink.hashed_gfid,
buf->ia_gfid);
+ gf_msg_debug (this->name, 0, "Found"
+ " one linkto file on hashed subvol %s "
+ "for %s: Skipping unlinking till "
+ "everywhere_done", subvol->name,
+ loc->path);
+
} else if (!ret && (fd_count == 0)) {
gf_log (this->name, GF_LOG_INFO,
"deleting stale linkfile %s on %s",
@@ -1452,6 +1553,9 @@ dht_lookup_everywhere (call_frame_t *frame, xlator_t *this, loc_t *loc)
if (!local->inode)
local->inode = inode_ref (loc->inode);
+ gf_msg_debug (this->name, 0,
+ "winding lookup call to %d subvols", call_cnt);
+
for (i = 0; i < call_cnt; i++) {
STACK_WIND (frame, dht_lookup_everywhere_cbk,
conf->subvolumes[i],
@@ -1659,8 +1763,12 @@ dht_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
if (!op_ret && uuid_is_null (local->gfid))
memcpy (local->gfid, stbuf->ia_gfid, 16);
+ gf_msg_debug (this->name, 0,
+ "fresh_lookup returned for %s with op_ret %d and "
+ "op_errno %d", loc->path, op_ret, op_errno);
+
if (ENTRY_MISSING (op_ret, op_errno)) {
- gf_msg_trace (this->name, 0, "Entry %s missing on subvol"
+ gf_log (this->name, GF_LOG_INFO, "Entry %s missing on subvol"
" %s", loc->path, prev->this->name);
if (conf->search_unhashed == GF_DHT_LOOKUP_UNHASHED_ON) {
local->op_errno = ENOENT;
@@ -1721,6 +1829,10 @@ dht_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
subvol = dht_linkfile_subvol (this, inode, stbuf, xattr);
if (!subvol) {
+
+ gf_log (this->name, GF_LOG_INFO, "linkfile not having link "
+ "subvol for %s", loc->path);
+
gf_msg_debug (this->name, 0,
"linkfile not having link subvolume. path=%s",
loc->path);
@@ -1728,6 +1840,10 @@ dht_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
return 0;
}
+ gf_msg_debug (this->name, 0,
+ "Calling lookup on linkto target %s for path %s",
+ subvol->name, loc->path);
+
STACK_WIND (frame, dht_lookup_linkfile_cbk,
subvol, subvol->fops->lookup,
&local->loc, local->xattr_req);
@@ -1874,6 +1990,13 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
dht_layout_unref (this, local->layout);
local->layout = NULL;
local->cached_subvol = NULL;
+
+ gf_msg_debug(this->name, 0,
+ "Called revalidate lookup for %s, "
+ "but layout->gen (%d) is less than "
+ "conf->gen (%d), calling fresh_lookup",
+ loc->path, layout->gen, conf->gen);
+
goto do_fresh_lookup;
}
@@ -1930,6 +2053,10 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
for (i = 0; i < call_cnt; i++) {
subvol = layout->list[i].xlator;
+ gf_msg_debug (this->name, 0, "calling "
+ "revalidate lookup for %s at %s",
+ loc->path, subvol->name);
+
STACK_WIND (frame, dht_revalidate_cbk,
subvol, subvol->fops->lookup,
&local->loc, local->xattr_req);
@@ -1972,10 +2099,12 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
dht_check_and_set_acl_xattr_req (loc->inode, local->xattr_req);
if (!hashed_subvol) {
+
gf_msg_debug (this->name, 0,
"no subvolume in layout for path=%s, "
"checking on all the subvols to see if "
"it is a directory", loc->path);
+
call_cnt = conf->subvolume_cnt;
local->call_cnt = call_cnt;
@@ -1986,6 +2115,10 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
goto err;
}
+ gf_msg_debug (this->name, 0,
+ "Found null hashed subvol. Calling lookup"
+ " on all nodes.");
+
for (i = 0; i < call_cnt; i++) {
STACK_WIND (frame, dht_lookup_dir_cbk,
conf->subvolumes[i],
@@ -1995,6 +2128,9 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
return 0;
}
+ gf_msg_debug (this->name, 0, "Calling fresh lookup for %s on"
+ " %s", loc->path, hashed_subvol->name);
+
STACK_WIND (frame, dht_lookup_cbk,
hashed_subvol, hashed_subvol->fops->lookup,
loc, local->xattr_req);
diff --git a/xlators/storage/posix/src/posix.c b/xlators/storage/posix/src/posix.c
index 84574734e2c..1e86d891675 100644
--- a/xlators/storage/posix/src/posix.c
+++ b/xlators/storage/posix/src/posix.c
@@ -1396,6 +1396,9 @@ posix_unlink (call_frame_t *frame, xlator_t *this,
UNLOCK (&loc->inode->lock);
+ gf_log (this->name, GF_LOG_INFO, "open-fd-key-status: "
+ "%"PRIu32" for %s", skip_unlink, real_path);
+
if (skip_unlink) {
op_ret = -1;
op_errno = EBUSY;
@@ -1423,6 +1426,9 @@ posix_unlink (call_frame_t *frame, xlator_t *this,
UNLOCK (&loc->inode->lock);
+ gf_log (this->name, GF_LOG_INFO, "linkto_xattr status: "
+ "%"PRIu32" for %s", skip_unlink, real_path);
+
if (skip_unlink) {
op_ret = -1;
op_errno = EBUSY;