From 0a4119e321be46bf274e1ee4251a15609ad09df7 Mon Sep 17 00:00:00 2001 From: Venkatesh Somyajulu Date: Thu, 11 Sep 2014 14:18:32 +0530 Subject: cluster/dht: Added code to capture races in dht-lookup path Change-Id: I9270d2d40ebd4b113ff961583dfda7754741f15b BUG: 1129541 Signed-off-by: Venkatesh Somyajulu Reviewed-on: http://review.gluster.org/8430 Tested-by: Gluster Build System Reviewed-by: Vijay Bellur (cherry picked from commit bb2d5f49b5684e6484af16a580870cfe104aecd2) Signed-off-by: Nithya Balachandran Reviewed-on: http://review.gluster.org/8731 Reviewed-by: Niels de Vos --- xlators/cluster/dht/src/dht-common.c | 148 +++++++++++++++++++++++++++++++++-- 1 file changed, 142 insertions(+), 6 deletions(-) (limited to 'xlators/cluster') 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); -- cgit