From 39ae62c39662a37fef9d0809438482ce441a98e0 Mon Sep 17 00:00:00 2001 From: Pranith Kumar K Date: Fri, 12 Apr 2013 11:06:44 +0530 Subject: protocol/server: Change logs to give more info on disconnects Change-Id: I8304a12df417be164c564e0696f72c3334f21569 BUG: 952138 Signed-off-by: Pranith Kumar K Reviewed-on: http://review.gluster.org/4824 Tested-by: Gluster Build System Reviewed-by: Vijay Bellur --- xlators/protocol/server/src/server-helpers.c | 87 ++++++++++++++++++---------- xlators/protocol/server/src/server.c | 17 +++++- xlators/protocol/server/src/server.h | 3 +- 3 files changed, 71 insertions(+), 36 deletions(-) (limited to 'xlators/protocol') diff --git a/xlators/protocol/server/src/server-helpers.c b/xlators/protocol/server/src/server-helpers.c index e2bbf4bcb..246a5ec6c 100644 --- a/xlators/protocol/server/src/server-helpers.c +++ b/xlators/protocol/server/src/server-helpers.c @@ -272,7 +272,6 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, xlator_t *bound_xl = NULL; struct _locker *locker = NULL, *tmp = NULL; int ret = -1; - char *path = NULL; GF_VALIDATE_OR_GOTO ("server", this, out); GF_VALIDATE_OR_GOTO ("server", conn, out); @@ -307,20 +306,9 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, memset (&tmp_frame->root->lk_owner, 0, sizeof (gf_lkowner_t)); if (locker->fd) { - GF_ASSERT (locker->fd->inode); - - ret = inode_path (locker->fd->inode, NULL, &path); - - if (ret > 0) { - gf_log (this->name, GF_LOG_INFO, "finodelk " - "released on %s", path); - GF_FREE (path); - } else { - - gf_log (this->name, GF_LOG_INFO, "finodelk " - "released on inode with gfid %s", - uuid_utoa (locker->fd->inode->gfid)); - } + gf_log (this->name, GF_LOG_DEBUG, "finodelk " + "released on inode with gfid %s", + uuid_utoa (locker->fd->inode->gfid)); STACK_WIND (tmp_frame, server_nop_cbk, bound_xl, bound_xl->fops->finodelk, @@ -328,7 +316,7 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, locker->fd, F_SETLK, &flock, NULL); fd_unref (locker->fd); } else { - gf_log (this->name, GF_LOG_INFO, "inodelk released " + gf_log (this->name, GF_LOG_DEBUG, "inodelk released " "on %s", locker->loc.path); STACK_WIND (tmp_frame, server_nop_cbk, bound_xl, @@ -356,18 +344,9 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, if (locker->fd) { GF_ASSERT (locker->fd->inode); - ret = inode_path (locker->fd->inode, NULL, &path); - - if (ret > 0) { - gf_log (this->name, GF_LOG_INFO, "fentrylk " - "released on %s", path); - GF_FREE (path); - } else { - - gf_log (this->name, GF_LOG_INFO, "fentrylk " - "released on inode with gfid %s", - uuid_utoa (locker->fd->inode->gfid)); - } + gf_log (this->name, GF_LOG_DEBUG, "fentrylk " + "released on inode with gfid %s", + uuid_utoa (locker->fd->inode->gfid)); STACK_WIND (tmp_frame, server_nop_cbk, bound_xl, bound_xl->fops->fentrylk, @@ -376,7 +355,7 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, ENTRYLK_UNLOCK, ENTRYLK_WRLCK, NULL); fd_unref (locker->fd); } else { - gf_log (this->name, GF_LOG_INFO, "entrylk released " + gf_log (this->name, GF_LOG_DEBUG, "entrylk released " "on %s", locker->loc.path); STACK_WIND (tmp_frame, server_nop_cbk, bound_xl, @@ -526,7 +505,6 @@ out: return ret; } - int server_connection_cleanup (xlator_t *this, server_connection_t *conn, int32_t flags) @@ -561,6 +539,52 @@ out: return ret; } +void +server_log_conn_destroy (server_connection_t *conn) +{ + int i = 0; + char *rsp_failures_msg = NULL; + char *free_ptr = NULL; + char *msg = NULL; + char *failed_to_rsp = ""; + char *sep1 = " - "; + char *sep2 = ", "; + int msg_len = 0; + + for (i = GF_FOP_NULL + 1; i < GF_FOP_MAXVALUE; i++) { + msg_len += strlen (gf_fop_list[i]); + msg_len += 20; //Max len of uint64_t is 20 + //Separators for fop-string, count + msg_len += strlen (sep1) + strlen (sep2); + } + + rsp_failures_msg = GF_CALLOC (msg_len + 1, 1, gf_common_mt_char); + if (rsp_failures_msg == NULL) { + rsp_failures_msg = ""; + goto out; + } else { + free_ptr = rsp_failures_msg; + } + + msg = rsp_failures_msg; + for (i = GF_FOP_NULL + 1; i < GF_FOP_MAXVALUE; i++) { + if (!conn->rsp_failure_fops[i]) + continue; + //Note: Please make sure the size is calculated appropriately + //if you plan to change the format string. + msg += sprintf (msg, "%s%s%"PRIu64"%s", gf_fop_list[i], sep1, + conn->rsp_failure_fops[i], sep2); + } + if (rsp_failures_msg[0]) { + failed_to_rsp = " - Failed to respond to following operations:"; + //Remove last comma + rsp_failures_msg[strlen (rsp_failures_msg) - 2] = '\0'; + } +out: + gf_log (conn->this->name, GF_LOG_INFO, "destroyed connection of " + "%s %s %s", conn->id, failed_to_rsp, rsp_failures_msg); + GF_FREE (free_ptr); +} int server_connection_destroy (xlator_t *this, server_connection_t *conn) @@ -610,8 +634,7 @@ server_connection_destroy (xlator_t *this, server_connection_t *conn) gf_fd_fdtable_destroy (fdtable); } - gf_log (this->name, GF_LOG_INFO, "destroyed connection of %s", - conn->id); + server_log_conn_destroy (conn); pthread_mutex_destroy (&conn->lock); GF_FREE (conn->id); diff --git a/xlators/protocol/server/src/server.c b/xlators/protocol/server/src/server.c index 7aafbdf0a..63e3ce918 100644 --- a/xlators/protocol/server/src/server.c +++ b/xlators/protocol/server/src/server.c @@ -121,6 +121,7 @@ server_submit_reply (call_frame_t *frame, rpcsvc_request_t *req, void *arg, char new_iobref = 0; server_connection_t *conn = NULL; gf_boolean_t lk_heal = _gf_false; + glusterfs_fop_t fop = GF_FOP_NULL; GF_VALIDATE_OR_GOTO ("server", req, ret); @@ -164,14 +165,23 @@ server_submit_reply (call_frame_t *frame, rpcsvc_request_t *req, void *arg, */ iobuf_unref (iob); if (ret == -1) { - gf_log_callingfn ("", GF_LOG_ERROR, "Reply submission failed"); if (frame && conn && !lk_heal) { + fop = frame->root->op; + if ((GF_FOP_NULL < fop) && + (fop < GF_FOP_MAXVALUE)) { + pthread_mutex_lock (&conn->lock); + { + conn->rsp_failure_fops[fop]++; + } + pthread_mutex_unlock (&conn->lock); + } server_connection_cleanup (frame->this, conn, INTERNAL_LOCKS | POSIX_LOCKS); } else { + gf_log_callingfn ("", GF_LOG_ERROR, + "Reply submission failed"); /* TODO: Failure of open(dir), create, inodelk, entrylk or lk fops send failure must be handled specially. */ - ; } goto ret; } @@ -759,7 +769,8 @@ server_rpc_notify (rpcsvc_t *rpc, void *xl, rpcsvc_event_t event, break; gf_log (this->name, GF_LOG_INFO, "disconnecting connection" - "from %s", conn->id); + " from %s, Number of pending operations: %"PRIu64, + conn->id, conn->ref); /* If lock self heal is off, then destroy the conn object, else register a grace timer event */ diff --git a/xlators/protocol/server/src/server.h b/xlators/protocol/server/src/server.h index e7eccfd11..1da574934 100644 --- a/xlators/protocol/server/src/server.h +++ b/xlators/protocol/server/src/server.h @@ -53,7 +53,7 @@ struct _lock_table { struct _server_connection { struct list_head list; char *id; - int ref; + uint64_t ref; int bind_ref; pthread_mutex_t lock; fdtable_t *fdtable; @@ -62,6 +62,7 @@ struct _server_connection { xlator_t *bound_xl; xlator_t *this; uint32_t lk_version; + uint64_t rsp_failure_fops[GF_FOP_MAXVALUE]; }; typedef struct _server_connection server_connection_t; -- cgit