summaryrefslogtreecommitdiffstats
path: root/xlators/protocol/client/src/client-handshake.c
diff options
context:
space:
mode:
Diffstat (limited to 'xlators/protocol/client/src/client-handshake.c')
-rw-r--r--xlators/protocol/client/src/client-handshake.c230
1 files changed, 151 insertions, 79 deletions
diff --git a/xlators/protocol/client/src/client-handshake.c b/xlators/protocol/client/src/client-handshake.c
index 4577dda5d65..b5c894fdcff 100644
--- a/xlators/protocol/client/src/client-handshake.c
+++ b/xlators/protocol/client/src/client-handshake.c
@@ -56,20 +56,25 @@ rpc_client_ping_timer_expired (void *data)
this = data;
if (!this || !this->private) {
+ gf_log ("", GF_LOG_WARNING, "xlator initialization not done");
goto out;
}
conf = this->private;
clnt = conf->rpc;
- if (!clnt)
+ if (!clnt) {
+ gf_log (this->name, GF_LOG_WARNING, "rpc not initialized");
goto out;
+ }
conn = &clnt->conn;
trans = conn->trans;
- if (!trans)
+ if (!trans) {
+ gf_log (this->name, GF_LOG_WARNING, "transport not initialized");
goto out;
+ }
pthread_mutex_lock (&conn->lock);
{
@@ -97,8 +102,8 @@ rpc_client_ping_timer_expired (void *data)
rpc_client_ping_timer_expired,
(void *) this);
if (conn->ping_timer == NULL)
- gf_log (trans->name, GF_LOG_DEBUG,
- "unable to setup timer");
+ gf_log (trans->name, GF_LOG_WARNING,
+ "unable to setup ping timer");
} else {
conn->ping_started = 0;
@@ -109,8 +114,8 @@ rpc_client_ping_timer_expired (void *data)
pthread_mutex_unlock (&conn->lock);
if (disconnect) {
- gf_log (trans->name, GF_LOG_ERROR,
- "Server %s has not responded in the last %d "
+ gf_log (trans->name, GF_LOG_CRITICAL,
+ "server %s has not responded in the last %d "
"seconds, disconnecting.",
conn->trans->peerinfo.identifier,
conf->opt.ping_timeout);
@@ -134,17 +139,22 @@ client_start_ping (void *data)
int frame_count = 0;
this = data;
- if (!this || !this->private)
+ if (!this || !this->private) {
+ gf_log ("", GF_LOG_WARNING, "xlator not initialized");
goto fail;
+ }
conf = this->private;
- if (!conf->rpc)
+ if (!conf->rpc) {
+ gf_log (this->name, GF_LOG_WARNING, "rpc not initialized");
goto fail;
-
+ }
conn = &conf->rpc->conn;
- if (conf->opt.ping_timeout == 0)
+ if (conf->opt.ping_timeout == 0) {
+ gf_log (this->name, GF_LOG_INFO, "ping timeout is 0, returning");
return;
+ }
pthread_mutex_lock (&conn->lock);
{
@@ -163,12 +173,17 @@ client_start_ping (void *data)
/* using goto looked ugly here,
* hence getting out this way */
/* unlock */
+ gf_log (this->name, GF_LOG_DEBUG,
+ "returning as transport is already disconnected"
+ " OR there are no frames (%d || %d)",
+ frame_count, !conn->connected);
+
pthread_mutex_unlock (&conn->lock);
return;
}
if (frame_count < 0) {
- gf_log (this->name, GF_LOG_DEBUG,
+ gf_log (this->name, GF_LOG_WARNING,
"saved_frames->count is %"PRId64,
conn->saved_frames->count);
conn->saved_frames->count = 0;
@@ -183,8 +198,8 @@ client_start_ping (void *data)
(void *) this);
if (conn->ping_timer == NULL) {
- gf_log (this->name, GF_LOG_DEBUG,
- "unable to setup timer");
+ gf_log (this->name, GF_LOG_WARNING,
+ "unable to setup ping timer");
} else {
conn->ping_started = 1;
}
@@ -203,6 +218,7 @@ client_start_ping (void *data)
return;
fail:
+ gf_log ("", GF_LOG_ERROR, "failed to start ping timer");
if (frame) {
STACK_DESTROY (frame->root);
@@ -222,28 +238,31 @@ client_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
call_frame_t *frame = NULL;
clnt_conf_t *conf = NULL;
- if (!myframe)
+ if (!myframe) {
+ gf_log ("", GF_LOG_WARNING, "frame with the request is NULL");
goto out;
-
+ }
frame = myframe;
this = frame->this;
- if (!this || !this->private)
+ if (!this || !this->private) {
+ gf_log ("", GF_LOG_WARNING, "xlator private is not set");
goto out;
+ }
conf = this->private;
conn = &conf->rpc->conn;
if (req->rpc_status == -1) {
- if (conn->ping_timer != NULL) {
- gf_log (this->name, GF_LOG_DEBUG, "socket or ib"
- " related error");
- gf_timer_call_cancel (this->ctx, conn->ping_timer);
- conn->ping_timer = NULL;
- } else {
- /* timer expired and transport bailed out */
- gf_log (this->name, GF_LOG_DEBUG, "timer must have "
- "expired");
- }
+ if (conn->ping_timer != NULL) {
+ gf_log (this->name, GF_LOG_WARNING, "socket or ib"
+ " related error");
+ gf_timer_call_cancel (this->ctx, conn->ping_timer);
+ conn->ping_timer = NULL;
+ } else {
+ /* timer expired and transport bailed out */
+ gf_log (this->name, GF_LOG_WARNING, "timer must have "
+ "expired");
+ }
goto out;
}
@@ -260,8 +279,8 @@ client_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
client_start_ping, (void *)this);
if (conn->ping_timer == NULL)
- gf_log (this->name, GF_LOG_DEBUG,
- "gf_timer_call_after() returned NULL");
+ gf_log (this->name, GF_LOG_WARNING,
+ "failed to set the ping timer");
}
pthread_mutex_unlock (&conn->lock);
out:
@@ -281,22 +300,32 @@ client3_getspec_cbk (struct rpc_req *req, struct iovec *iov, int count,
frame = myframe;
- if (-1 == req->rpc_status) {
+ if (!frame || !frame->this) {
+ gf_log ("", GF_LOG_ERROR, "frame not found with the request, "
+ "returning EINVAL");
rsp.op_ret = -1;
rsp.op_errno = EINVAL;
goto out;
}
+ if (-1 == req->rpc_status) {
+ gf_log (frame->this->name, GF_LOG_WARNING,
+ "received RPC status error, returning ENOTCONN");
+ rsp.op_ret = -1;
+ rsp.op_errno = ENOTCONN;
+ goto out;
+ }
ret = xdr_to_getspec_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (frame->this->name, GF_LOG_ERROR,
+ "XDR decoding failed, returning EINVAL");
rsp.op_ret = -1;
rsp.op_errno = EINVAL;
goto out;
}
if (-1 == rsp.op_ret) {
- gf_log (frame->this->name, GF_LOG_ERROR,
+ gf_log (frame->this->name, GF_LOG_WARNING,
"failed to get the 'volume file' from server");
goto out;
}
@@ -337,6 +366,7 @@ int32_t client3_getspec (call_frame_t *frame, xlator_t *this, void *data)
return 0;
unwind:
+ gf_log (this->name, GF_LOG_WARNING, "failed to send the request");
STACK_UNWIND_STRICT (getspec, frame, -1, op_errno, NULL);
return 0;
@@ -380,10 +410,15 @@ client3_1_reopen_cbk (struct rpc_req *req, struct iovec *iov, int count,
call_frame_t *frame = NULL;
frame = myframe;
+ if (!frame || !frame->this)
+ goto out;
+
local = frame->local;
conf = frame->this->private;
if (-1 == req->rpc_status) {
+ gf_log (frame->this->name, GF_LOG_WARNING,
+ "received RPC status error, returning ENOTCONN");
rsp.op_ret = -1;
rsp.op_errno = ENOTCONN;
goto out;
@@ -391,18 +426,18 @@ client3_1_reopen_cbk (struct rpc_req *req, struct iovec *iov, int count,
ret = xdr_to_open_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (frame->this->name, GF_LOG_ERROR, "XDR decoding failed");
rsp.op_ret = -1;
rsp.op_errno = EINVAL;
goto out;
}
if (rsp.op_ret < 0) {
- gf_log (frame->this->name, GF_LOG_NORMAL,
+ gf_log (frame->this->name, GF_LOG_WARNING,
"reopen on %s failed (%s)",
local->loc.path, strerror (rsp.op_errno));
} else {
- gf_log (frame->this->name, GF_LOG_NORMAL,
+ gf_log (frame->this->name, GF_LOG_DEBUG,
"reopen on %s succeeded (remote-fd = %"PRId64")",
local->loc.path, rsp.fd);
}
@@ -415,6 +450,7 @@ client3_1_reopen_cbk (struct rpc_req *req, struct iovec *iov, int count,
fdctx = local->fdctx;
if (!fdctx) {
+ gf_log (frame->this->name, GF_LOG_WARNING, "fdctx not found");
ret = -1;
goto out;
}
@@ -437,18 +473,18 @@ client3_1_reopen_cbk (struct rpc_req *req, struct iovec *iov, int count,
ret = client_attempt_lock_recovery (frame->this, local->fdctx);
if (ret < 0) {
gf_log (frame->this->name, GF_LOG_DEBUG,
- "No locks on fd to recover");
+ "lock recovery not attempted on fd");
} else {
- gf_log (frame->this->name, GF_LOG_DEBUG,
- "Need to attempt lock recovery on %lld open fds",
- (unsigned long long) fd_count);
+ gf_log (frame->this->name, GF_LOG_INFO,
+ "need to attempt lock recovery on %"PRIu64
+ " open fds", fd_count);
}
- } else {
- fd_count = decrement_reopen_fd_count (frame->this, conf);
}
-
out:
+ if (!attempt_lock_recovery)
+ fd_count = decrement_reopen_fd_count (frame->this, conf);
+
if (fdctx)
client_fdctx_destroy (frame->this, fdctx);
@@ -479,10 +515,11 @@ client3_1_reopendir_cbk (struct rpc_req *req, struct iovec *iov, int count,
goto out;
local = frame->local;
- frame->local = NULL;
conf = frame->this->private;
if (-1 == req->rpc_status) {
+ gf_log (frame->this->name, GF_LOG_WARNING,
+ "received RPC status error, returning ENOTCONN");
rsp.op_ret = -1;
rsp.op_errno = ENOTCONN;
goto out;
@@ -490,14 +527,14 @@ client3_1_reopendir_cbk (struct rpc_req *req, struct iovec *iov, int count,
ret = xdr_to_opendir_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (frame->this->name, GF_LOG_ERROR, "XDR decoding failed");
rsp.op_ret = -1;
rsp.op_errno = EINVAL;
goto out;
}
if (rsp.op_ret < 0) {
- gf_log (frame->this->name, GF_LOG_NORMAL,
+ gf_log (frame->this->name, GF_LOG_WARNING,
"reopendir on %s failed (%s)",
local->loc.path, strerror (rsp.op_errno));
} else {
@@ -506,23 +543,29 @@ client3_1_reopendir_cbk (struct rpc_req *req, struct iovec *iov, int count,
local->loc.path, rsp.fd);
}
- if (-1 != rsp.op_ret) {
- fdctx = local->fdctx;
- if (fdctx) {
- pthread_mutex_lock (&conf->lock);
- {
- fdctx->remote_fd = rsp.fd;
+ if (-1 == rsp.op_ret) {
+ ret = -1;
+ goto out;
+ }
- if (!fdctx->released) {
- list_add_tail (&fdctx->sfd_pos, &conf->saved_fds);
- fdctx = NULL;
- }
- }
- pthread_mutex_unlock (&conf->lock);
+ fdctx = local->fdctx;
+ if (!fdctx) {
+ gf_log (frame->this->name, GF_LOG_WARNING, "fdctx not found");
+ ret = -1;
+ goto out;
+ }
+
+ pthread_mutex_lock (&conf->lock);
+ {
+ fdctx->remote_fd = rsp.fd;
+
+ if (!fdctx->released) {
+ list_add_tail (&fdctx->sfd_pos, &conf->saved_fds);
+ fdctx = NULL;
}
}
+ pthread_mutex_unlock (&conf->lock);
- decrement_reopen_fd_count (frame->this, conf);
ret = 0;
out:
@@ -561,6 +604,9 @@ protocol_client_reopendir (xlator_t *this, clnt_fd_ctx_t *fdctx)
ret = inode_path (inode, NULL, &path);
if (ret < 0) {
+ gf_log (this->name, GF_LOG_WARNING,
+ "couldn't build path from inode %s",
+ uuid_utoa (inode->gfid));
goto out;
}
@@ -599,6 +645,8 @@ protocol_client_reopendir (xlator_t *this, clnt_fd_ctx_t *fdctx)
return ret;
out:
+ gf_log ("", GF_LOG_ERROR, "failed to send the re-opendir request");
+
if (frame) {
frame->local = NULL;
STACK_DESTROY (frame->root);
@@ -636,6 +684,9 @@ protocol_client_reopen (xlator_t *this, clnt_fd_ctx_t *fdctx)
ret = inode_path (inode, NULL, &path);
if (ret < 0) {
+ gf_log (this->name, GF_LOG_WARNING,
+ "couldn't build path from inode %s",
+ uuid_utoa (inode->gfid));
goto out;
}
@@ -674,6 +725,8 @@ protocol_client_reopen (xlator_t *this, clnt_fd_ctx_t *fdctx)
return ret;
out:
+ gf_log ("", GF_LOG_ERROR, "failed to send the re-open request");
+
if (frame) {
frame->local = NULL;
STACK_DESTROY (frame->root);
@@ -742,9 +795,8 @@ client_post_handshake (call_frame_t *frame, xlator_t *this)
}
} else {
gf_log (this->name, GF_LOG_DEBUG,
- "No open fds - notifying all parents child up");
+ "no open fds - notifying all parents child up");
client_notify_parents_child_up (this);
-
}
out:
return 0;
@@ -771,13 +823,15 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
conf = this->private;
if (-1 == req->rpc_status) {
+ gf_log (frame->this->name, GF_LOG_WARNING,
+ "received RPC status error");
op_ret = -1;
goto out;
}
ret = xdr_to_setvolume_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (this->name, GF_LOG_ERROR, "XDR decoding failed");
op_ret = -1;
goto out;
}
@@ -785,7 +839,8 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
op_errno = gf_error_to_errno (rsp.op_errno);
if (-1 == rsp.op_ret) {
gf_log (frame->this->name, GF_LOG_WARNING,
- "failed to set the volume");
+ "failed to set the volume (%s)",
+ (op_errno)? strerror (op_errno) : "--");
}
reply = dict_new ();
@@ -796,7 +851,7 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
ret = dict_unserialize (rsp.dict.dict_val,
rsp.dict.dict_len, &reply);
if (ret < 0) {
- gf_log (frame->this->name, GF_LOG_DEBUG,
+ gf_log (frame->this->name, GF_LOG_WARNING,
"failed to unserialize buffer to dict");
goto out;
}
@@ -804,13 +859,13 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
ret = dict_get_str (reply, "ERROR", &remote_error);
if (ret < 0) {
- gf_log (this->name, GF_LOG_DEBUG,
+ gf_log (this->name, GF_LOG_WARNING,
"failed to get ERROR string from reply dict");
}
ret = dict_get_str (reply, "process-uuid", &process_uuid);
if (ret < 0) {
- gf_log (this->name, GF_LOG_DEBUG,
+ gf_log (this->name, GF_LOG_WARNING,
"failed to get 'process-uuid' from reply dict");
}
@@ -830,10 +885,14 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
}
goto out;
}
+
ret = dict_get_str (this->options, "remote-subvolume",
&remote_subvol);
- if (ret || !remote_subvol)
+ if (ret || !remote_subvol) {
+ gf_log (this->name, GF_LOG_WARNING,
+ "failed to find key 'remote-subvolume' in the options");
goto out;
+ }
/* TODO: currently setpeer path is broken */
/*
@@ -857,7 +916,7 @@ client_setvolume_cbk (struct rpc_req *req, struct iovec *iov, int count, void *m
}
*/
- gf_log (this->name, GF_LOG_NORMAL,
+ gf_log (this->name, GF_LOG_INFO,
"Connected to %s, attached to remote volume '%s'.",
conf->rpc->conn.trans->peerinfo.identifier,
remote_subvol);
@@ -878,6 +937,7 @@ out:
* background, for now, don't hang here,
* tell the parents that i am all ok..
*/
+ gf_log (this->name, GF_LOG_INFO, "sending CHILD_CONNECTING event");
parent = this->parents;
while (parent) {
xlator_notify (parent->xlator,
@@ -992,6 +1052,7 @@ client_setvolume (xlator_t *this, struct rpc_clnt *rpc)
NULL, 0, NULL);
fail:
+
if (ret) {
config.remote_port = -1;
rpc_clnt_reconfig (conf->rpc, &config);
@@ -1010,8 +1071,11 @@ select_server_supported_programs (xlator_t *this, gf_prog_detail *prog)
clnt_conf_t *conf = NULL;
int ret = -1;
- if (!this || !prog)
+ if (!this || !prog) {
+ gf_log ("", GF_LOG_WARNING,
+ "xlator not found OR RPC program not found");
goto out;
+ }
conf = this->private;
trav = prog;
@@ -1046,8 +1110,11 @@ server_has_portmap (xlator_t *this, gf_prog_detail *prog)
gf_prog_detail *trav = NULL;
int ret = -1;
- if (!this || !prog)
+ if (!this || !prog) {
+ gf_log ("", GF_LOG_WARNING,
+ "xlator not found OR RPC program not found");
goto out;
+ }
trav = prog;
@@ -1078,26 +1145,29 @@ client_query_portmap_cbk (struct rpc_req *req, struct iovec *iov, int count, voi
xlator_t *this = NULL;
frame = myframe;
- if (!frame || !frame->this || !frame->this->private)
+ if (!frame || !frame->this || !frame->this->private) {
+ gf_log ("", GF_LOG_WARNING,
+ "frame not found with rpc request");
goto out;
-
+ }
this = frame->this;
conf = frame->this->private;
if (-1 == req->rpc_status) {
- gf_log ("", 1, "some error, retry again later");
+ gf_log (this->name, GF_LOG_WARNING,
+ "received RPC status error, try again later");
goto out;
}
ret = xdr_to_pmap_port_by_brick_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (this->name, GF_LOG_ERROR, "XDR decoding failed");
goto out;
}
if (-1 == rsp.op_ret) {
ret = -1;
- gf_log (frame->this->name, GF_LOG_ERROR,
+ gf_log (this->name, GF_LOG_ERROR,
"failed to get the port number for remote subvolume");
goto out;
}
@@ -1175,17 +1245,18 @@ client_dump_version_cbk (struct rpc_req *req, struct iovec *iov, int count,
conf = frame->this->private;
if (-1 == req->rpc_status) {
- gf_log ("", 1, "some error, retry again later");
+ gf_log (frame->this->name, GF_LOG_WARNING,
+ "received RPC status error");
goto out;
}
ret = xdr_to_dump_rsp (*iov, &rsp);
if (ret < 0) {
- gf_log ("", GF_LOG_ERROR, "error");
+ gf_log (frame->this->name, GF_LOG_ERROR, "XDR decoding failed");
goto out;
}
if (-1 == rsp.op_ret) {
- gf_log (frame->this->name, GF_LOG_ERROR,
+ gf_log (frame->this->name, GF_LOG_WARNING,
"failed to get the 'versions' from server");
goto out;
}
@@ -1200,8 +1271,7 @@ client_dump_version_cbk (struct rpc_req *req, struct iovec *iov, int count,
ret = select_server_supported_programs (frame->this, rsp.prog);
if (ret) {
gf_log (frame->this->name, GF_LOG_ERROR,
- "Server versions are not present in this "
- "release");
+ "server doesn't support the version");
goto out;
}
@@ -1236,8 +1306,10 @@ client_handshake (xlator_t *this, struct rpc_clnt *rpc)
int ret = 0;
conf = this->private;
- if (!conf->handshake)
+ if (!conf->handshake) {
+ gf_log (this->name, GF_LOG_WARNING, "handshake program not found");
goto out;
+ }
frame = create_frame (this, this->ctx->pool);
if (!frame)