summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorVenkatesh Somyajulu <vsomyaju@redhat.com>2014-09-11 14:18:32 +0530
committerNiels de Vos <ndevos@redhat.com>2014-10-01 03:37:12 -0700
commit0a4119e321be46bf274e1ee4251a15609ad09df7 (patch)
treef048e16088da306955ec4a795e1cd2dcb3205501
parent53cbf3146dacdd68f0a24ce6b2f924c77d79a411 (diff)
cluster/dht: Added code to capture races in dht-lookup path
Change-Id: I9270d2d40ebd4b113ff961583dfda7754741f15b BUG: 1129541 Signed-off-by: Venkatesh Somyajulu <vsomyaju@redhat.com> Reviewed-on: http://review.gluster.org/8430 Tested-by: Gluster Build System <jenkins@build.gluster.com> Reviewed-by: Vijay Bellur <vbellur@redhat.com> (cherry picked from commit bb2d5f49b5684e6484af16a580870cfe104aecd2) Signed-off-by: Nithya Balachandran <nbalacha@redhat.com> Reviewed-on: http://review.gluster.org/8731 Reviewed-by: Niels de Vos <ndevos@redhat.com>
-rw-r--r--xlators/cluster/dht/src/dht-common.c148
-rw-r--r--xlators/storage/posix/src/posix.c6
2 files changed, 148 insertions, 6 deletions
diff --git a/xlators/cluster/dht/src/dht-common.c b/xlators/cluster/dht/src/dht-common.c
index 586321f96d6..52d9e50cd1e 100644
--- a/xlators/cluster/dht/src/dht-common.c
+++ b/xlators/cluster/dht/src/dht-common.c
@@ -453,9 +453,12 @@ 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_log (this->name, GF_LOG_DEBUG,
- "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;
}
@@ -552,6 +555,12 @@ dht_revalidate_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
LOCK (&frame->lock);
{
+
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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;
@@ -575,6 +584,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_log (this->name, GF_LOG_DEBUG,
+ "found ENOENT for %s. "
+ "Setting "
+ "need_lookup_everywhere"
+ " flag to 1",
+ local->loc.path);
+
local->need_lookup_everywhere = 1;
}
}
@@ -772,9 +789,16 @@ dht_lookup_linkfile_create_cbk (call_frame_t *frame, void *cookie,
}
unwind:
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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,
@@ -868,12 +892,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);
@@ -950,12 +986,15 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
xlator_t *hashed_subvol = NULL;
xlator_t *cached_subvol = NULL;
dht_layout_t *layout = NULL;
+ char gfid[GF_UUID_BUF_SIZE] = {0};
gf_boolean_t found_non_linkto_on_hashed = _gf_false;
local = frame->local;
hashed_subvol = local->hashed_subvol;
cached_subvol = local->cached_subvol;
+ uuid_unparse (local->loc.gfid, gfid);
+
if (local->file_count && local->dir_count) {
gf_log (this->name, GF_LOG_ERROR,
"path %s exists as a file on one subvolume "
@@ -972,6 +1011,10 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
return 0;
}
+ gf_log (this->name, GF_LOG_DEBUG, "STATUS: hashed_subvol %s "
+ "cached_subvol %s",
+ (hashed_subvol == NULL)?"null":hashed_subvol->name,
+ (cached_subvol == NULL)?"null":cached_subvol->name);
if (!cached_subvol) {
@@ -1013,7 +1056,14 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
NULL, NULL, NULL, NULL);
} else {
local->skip_unlink.handle_valid_link = _gf_false;
- STACK_WIND (frame,
+
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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,
@@ -1022,6 +1072,11 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
} else {
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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);
}
@@ -1045,6 +1100,11 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
} else if ((local->file_count == 1) &&
(hashed_subvol == cached_subvol)) {
+ gf_log (this->name, GF_LOG_DEBUG,
+ "found cached file on hashed subvolume "
+ "so store in context and return for %s",
+ local->loc.path);
+
found_non_linkto_on_hashed = _gf_true;
}
@@ -1090,10 +1150,28 @@ dht_lookup_everywhere_done (call_frame_t *frame, xlator_t *this)
(local->loc.parent, this,
&local->postparent, 1);
}
+
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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_log (this->name, GF_LOG_DEBUG,
+ "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) {
@@ -1172,9 +1250,9 @@ preset_layout:
if (!hashed_subvol) {
gf_log (this->name, GF_LOG_INFO,
- "cannot create linkfile file for %s on %s: "
- "hashed subvolume cannot be found.",
- local->loc.path, cached_subvol->name);
+ "Cannot create linkfile file 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;
@@ -1254,6 +1332,11 @@ dht_lookup_everywhere_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
prev = cookie;
subvol = prev->this;
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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) {
@@ -1273,6 +1356,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_log (this->name, GF_LOG_DEBUG,
+ "Found linktofile on %s for %s",
+ subvol->name, loc->path);
+
+ }
is_dir = check_is_dir (inode, buf, xattr);
if (is_linkfile) {
@@ -1297,14 +1388,19 @@ dht_lookup_everywhere_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
} else {
local->file_count++;
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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_log (this->name, GF_LOG_DEBUG,
- "found on %s file %s",
+ "storing cached on %s file %s",
subvol->name, loc->path);
dht_iatt_merge (this, &local->postparent,
@@ -1348,6 +1444,12 @@ unlock:
uuid_copy (local->skip_unlink.hashed_gfid,
buf->ia_gfid);
+ gf_log (this->name, GF_LOG_DEBUG, "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)) {
dict_req = dict_new ();
@@ -1420,6 +1522,9 @@ dht_lookup_everywhere (call_frame_t *frame, xlator_t *this, loc_t *loc)
if (!local->inode)
local->inode = inode_ref (loc->inode);
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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],
@@ -1618,9 +1723,14 @@ 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_log (this->name, GF_LOG_DEBUG,
+ "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_log (this->name, GF_LOG_TRACE, "Entry %s missing on subvol"
" %s", loc->path, prev->this->name);
+
if (conf->search_unhashed == GF_DHT_LOOKUP_UNHASHED_ON) {
local->op_errno = ENOENT;
dht_lookup_everywhere (frame, this, loc);
@@ -1683,10 +1793,15 @@ dht_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this,
gf_log (this->name, GF_LOG_DEBUG,
"linkfile not having link subvolume. path=%s",
loc->path);
+
dht_lookup_everywhere (frame, this, loc);
return 0;
}
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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);
@@ -1839,6 +1954,13 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
dht_layout_unref (this, local->layout);
local->layout = NULL;
local->cached_subvol = NULL;
+
+ gf_log(this->name, GF_LOG_DEBUG,
+ "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;
}
@@ -1892,6 +2014,10 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
for (i = 0; i < call_cnt; i++) {
subvol = layout->list[i].xlator;
+ gf_log (this->name, GF_LOG_DEBUG, "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);
@@ -1931,10 +2057,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_log (this->name, GF_LOG_DEBUG,
"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;
@@ -1945,6 +2073,10 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
goto err;
}
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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],
@@ -1954,6 +2086,10 @@ dht_lookup (call_frame_t *frame, xlator_t *this,
return 0;
}
+ gf_log (this->name, GF_LOG_DEBUG,
+ "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 605d282d355..3ab2df70a3e 100644
--- a/xlators/storage/posix/src/posix.c
+++ b/xlators/storage/posix/src/posix.c
@@ -1452,6 +1452,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;
@@ -1479,6 +1482,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;