From 0349ec857004428f29b50f3604e5ab126dfb407e Mon Sep 17 00:00:00 2001 From: Amar Tumballi Date: Wed, 16 Mar 2011 09:43:27 +0000 Subject: protocol/server: log enhancements Signed-off-by: Amar Tumballi Signed-off-by: Vijay Bellur BUG: 2346 (Log message enhancements in GlusterFS - phase 1) URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=2346 --- xlators/protocol/server/src/server-handshake.c | 5 +- xlators/protocol/server/src/server-helpers.c | 22 ++- xlators/protocol/server/src/server-resolve.c | 22 ++- xlators/protocol/server/src/server.c | 28 ++-- xlators/protocol/server/src/server3_1-fops.c | 203 ++++++++++++++++--------- 5 files changed, 175 insertions(+), 105 deletions(-) (limited to 'xlators/protocol') diff --git a/xlators/protocol/server/src/server-handshake.c b/xlators/protocol/server/src/server-handshake.c index 1dc05f032b2..66b9ea78d23 100644 --- a/xlators/protocol/server/src/server-handshake.c +++ b/xlators/protocol/server/src/server-handshake.c @@ -102,7 +102,7 @@ _volfile_update_checksum (xlator_t *this, char *key, uint32_t checksum) } if (temp_volfile->checksum != checksum) { - gf_log (this->name, GF_LOG_CRITICAL, + gf_log (this->name, GF_LOG_INFO, "the volume file got modified between earlier access " "and now, this may lead to inconsistency between " "clients, advised to remount client"); @@ -211,7 +211,7 @@ _validate_volfile_checksum (xlator_t *this, char *key, fd = open (filename, O_RDONLY); if (-1 == fd) { ret = 0; - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "failed to open volume file (%s) : %s", filename, strerror (errno)); goto out; @@ -372,7 +372,6 @@ server_setvolume (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); op_ret = -1; op_errno = ENOMEM; goto fail; diff --git a/xlators/protocol/server/src/server-helpers.c b/xlators/protocol/server/src/server-helpers.c index 78d850fc75d..da3124ff784 100644 --- a/xlators/protocol/server/src/server-helpers.c +++ b/xlators/protocol/server/src/server-helpers.c @@ -162,8 +162,6 @@ gf_add_locker (struct _lock_table *table, const char *volume, new = GF_CALLOC (1, sizeof (struct _locker), gf_server_mt_locker_t); if (new == NULL) { - gf_log ("server", GF_LOG_ERROR, - "failed to allocate memory for \'struct _locker\'"); goto out; } INIT_LIST_HEAD (&new->lockers); @@ -259,8 +257,6 @@ gf_lock_table_new (void) new = GF_CALLOC (1, sizeof (struct _lock_table), gf_server_mt_lock_table_t); if (new == NULL) { - gf_log ("server-protocol", GF_LOG_CRITICAL, - "failed to allocate memory for new lock table"); goto out; } INIT_LIST_HEAD (&new->entrylk_lockers); @@ -331,8 +327,6 @@ do_lock_table_cleanup (xlator_t *this, server_connection_t *conn, tmp, &inodelk_lockers, lockers) { tmp_frame = copy_frame (frame); if (tmp_frame == NULL) { - gf_log (this->name, GF_LOG_ERROR, - "out of memory"); goto out; } /* @@ -483,8 +477,6 @@ do_fd_cleanup (xlator_t *this, server_connection_t *conn, call_frame_t *frame, if (fd != NULL) { tmp_frame = copy_frame (frame); if (tmp_frame == NULL) { - gf_log (this->name, GF_LOG_ERROR, - "out of memory"); goto out; } @@ -538,7 +530,6 @@ do_connection_cleanup (xlator_t *this, server_connection_t *conn, frame = create_frame (this, this->ctx->pool); if (frame == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); goto out; } @@ -896,10 +887,12 @@ server_alloc_frame (rpcsvc_request_t *req) GF_VALIDATE_OR_GOTO ("server", conn, out); frame = create_frame (conn->this, req->svc->ctx->pool); - GF_VALIDATE_OR_GOTO ("server", frame, out); + if (!frame) + goto out; state = GF_CALLOC (1, sizeof (*state), gf_server_mt_state_t); - GF_VALIDATE_OR_GOTO ("server", state, out); + if (!state) + goto out; if (conn->bound_xl) state->itable = conn->bound_xl->itable; @@ -928,7 +921,8 @@ get_frame_from_request (rpcsvc_request_t *req) GF_VALIDATE_OR_GOTO ("server", req, out); frame = server_alloc_frame (req); - GF_VALIDATE_OR_GOTO ("server", frame, out); + if (!frame) + goto out; frame->root->op = req->procnum; frame->root->type = req->type; @@ -1320,7 +1314,9 @@ server_print_request (call_frame_t *frame) conf = this->private; GF_VALIDATE_OR_GOTO ("server", conf, out); - GF_VALIDATE_OR_GOTO ("server", conf->trace, out); + + if (!conf->trace) + goto out; state = CALL_STATE (frame); diff --git a/xlators/protocol/server/src/server-resolve.c b/xlators/protocol/server/src/server-resolve.c index 1da41b2fd59..0b0487a242a 100644 --- a/xlators/protocol/server/src/server-resolve.c +++ b/xlators/protocol/server/src/server-resolve.c @@ -70,7 +70,8 @@ prepare_components (call_frame_t *frame) count = component_count (resolve->path); components = GF_CALLOC (sizeof (*components), count, gf_server_mt_resolv_comp_t); - GF_VALIDATE_OR_GOTO ("server", components, out); + if (!components) + goto out; resolve->components = components; @@ -194,6 +195,10 @@ resolve_deep_cbk (call_frame_t *frame, void *cookie, xlator_t *this, i = (long) cookie; if (op_ret == -1) { + gf_log (this->name, ((op_errno == ENOENT) ? GF_LOG_DEBUG : + GF_LOG_WARNING), + "%s: failed to resolve (%s)", + resolve->resolved, strerror (op_errno)); goto get_out_of_here; } @@ -285,6 +290,8 @@ resolve_path_simple (call_frame_t *frame) components = resolve->components; if (!components) { + gf_log ("", GF_LOG_INFO, + "failed to resolve, component not found"); resolve->op_ret = -1; resolve->op_errno = ENOENT; goto out; @@ -296,6 +303,8 @@ resolve_path_simple (call_frame_t *frame) } if (ino_idx == -1) { + gf_log ("", GF_LOG_INFO, + "failed to resolve, inode index not found"); resolve->op_ret = -1; resolve->op_errno = EINVAL; goto out; @@ -306,6 +315,8 @@ resolve_path_simple (call_frame_t *frame) goto noparent; if (!components[par_idx].inode) { + gf_log ("", GF_LOG_INFO, + "failed to resolve, parent inode not found"); resolve->op_ret = -1; resolve->op_errno = ENOENT; goto out; @@ -315,12 +326,16 @@ noparent: if (!components[ino_idx].inode && (resolve->type == RESOLVE_MUST || resolve->type == RESOLVE_EXACT)) { + gf_log ("", GF_LOG_INFO, + "failed to resolve, inode not found"); resolve->op_ret = -1; resolve->op_errno = ENOENT; goto out; } if (components[ino_idx].inode && resolve->type == RESOLVE_NOT) { + gf_log ("", GF_LOG_INFO, + "failed to resolve, inode found"); resolve->op_ret = -1; resolve->op_errno = EEXIST; goto out; @@ -399,7 +414,7 @@ resolve_entry_simple (call_frame_t *frame) } if (resolve->type == RESOLVE_NOT) { - gf_log (this->name, GF_LOG_DEBUG, "inode (pointer: %p ino:%" + gf_log (this->name, GF_LOG_INFO, "inode (pointer: %p ino:%" PRIu64") found for path (%s) while type is RESOLVE_NOT", inode, inode->ino, resolve->path); resolve->op_ret = -1; @@ -526,6 +541,7 @@ server_resolve_fd (call_frame_t *frame) state->fd = gf_fd_fdptr_get (conn->fdtable, fd_no); if (!state->fd) { + gf_log ("", GF_LOG_INFO, "fd not found in context"); resolve->op_ret = -1; resolve->op_errno = EBADF; } @@ -559,7 +575,7 @@ server_resolve (call_frame_t *frame) } else if (resolve->path) { - gf_log (frame->this->name, GF_LOG_WARNING, + gf_log (frame->this->name, GF_LOG_INFO, "pure path resolution for %s (%s)", resolve->path, gf_fop_list[frame->root->op]); resolve_path_deep (frame); diff --git a/xlators/protocol/server/src/server.c b/xlators/protocol/server/src/server.c index 5b2560f5828..c1bcf61e431 100644 --- a/xlators/protocol/server/src/server.c +++ b/xlators/protocol/server/src/server.c @@ -50,7 +50,7 @@ gfs_serialize_reply (rpcsvc_request_t *req, void *arg, gfs_serialize_t sfunc, */ iob = iobuf_get (req->svc->ctx->iobuf_pool); if (!iob) { - gf_log ("", GF_LOG_ERROR, "Failed to get iobuf"); + gf_log_callingfn ("", GF_LOG_ERROR, "Failed to get iobuf"); goto ret; } @@ -66,7 +66,7 @@ gfs_serialize_reply (rpcsvc_request_t *req, void *arg, gfs_serialize_t sfunc, /* Failed to Encode 'GlusterFS' msg in RPC is not exactly failure of RPC return values.. client should get notified about this, so there are no missing frames */ - gf_log ("", GF_LOG_ERROR, "Failed to encode message"); + gf_log_callingfn ("", GF_LOG_ERROR, "Failed to encode message"); req->rpc_err = GARBAGE_ARGS; retlen = 0; } @@ -105,7 +105,6 @@ server_submit_reply (call_frame_t *frame, rpcsvc_request_t *req, void *arg, if (!iobref) { iobref = iobref_new (); if (!iobref) { - gf_log ("", GF_LOG_ERROR, "out of memory"); goto ret; } @@ -134,7 +133,7 @@ server_submit_reply (call_frame_t *frame, rpcsvc_request_t *req, void *arg, */ iobuf_unref (iob); if (ret == -1) { - gf_log ("", GF_LOG_ERROR, "Reply submission failed"); + gf_log_callingfn ("", GF_LOG_ERROR, "Reply submission failed"); goto ret; } @@ -403,8 +402,8 @@ server_rpc_notify (rpcsvc_t *rpc, void *xl, rpcsvc_event_t event, if (!xl || !data) { - gf_log ("server", GF_LOG_WARNING, - "Calling rpc_notify without initializing"); + gf_log_callingfn ("server", GF_LOG_WARNING, + "Calling rpc_notify without initializing"); goto out; } @@ -482,12 +481,10 @@ validate_options (xlator_t *this, dict_t *options, char **op_errstr) data_t *data; gf_boolean_t trace; - - if (dict_get_int32 ( options, "inode-lru-limit", &inode_lru_limit) == 0){ if (!(inode_lru_limit < (1 * GF_UNIT_MB) && inode_lru_limit >1 )) { - gf_log (this->name, GF_LOG_DEBUG, "Validate inode-lru" + gf_log (this->name, GF_LOG_INFO, "Validate inode-lru" "-limit %d, was WRONG", inode_lru_limit); snprintf (errstr,1024, "Error, Greater than max value %d " ,inode_lru_limit); @@ -515,7 +512,6 @@ validate_options (xlator_t *this, dict_t *options, char **op_errstr) auth_modules = dict_new (); if (!auth_modules) { - gf_log (this->name, GF_LOG_ERROR, "Out of memory"); ret = -1; goto out; } @@ -587,7 +583,7 @@ reconfigure (xlator_t *this, dict_t *options) conf = this->private; if (!conf) { - gf_log (this->name, GF_LOG_DEBUG, "conf == null!!!"); + gf_log_callingfn (this->name, GF_LOG_DEBUG, "conf == null!!!"); goto out; } if (dict_get_int32 ( options, "inode-lru-limit", &inode_lru_limit) == 0){ @@ -709,6 +705,8 @@ init (xlator_t *this) //conf->rpc = rpc_svc_init (&conf->rpc_conf); conf->rpc = rpcsvc_init (this->ctx, this->options); if (conf->rpc == NULL) { + gf_log (this->name, GF_LOG_WARNING, + "creation of rpcsvc failed"); ret = -1; goto out; } @@ -716,7 +714,7 @@ init (xlator_t *this) ret = rpcsvc_create_listeners (conf->rpc, this->options, this->name); if (ret < 1) { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_WARNING, "creation of listener failed"); ret = -1; goto out; @@ -724,7 +722,7 @@ init (xlator_t *this) ret = rpcsvc_register_notify (conf->rpc, server_rpc_notify, this); if (ret) { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_WARNING, "registration of notify with rpcsvc failed"); goto out; } @@ -732,7 +730,7 @@ init (xlator_t *this) glusterfs3_1_fop_prog.options = this->options; ret = rpcsvc_program_register (conf->rpc, &glusterfs3_1_fop_prog); if (ret) { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_WARNING, "registration of program (name:%s, prognum:%d, " "progver:%d) failed", glusterfs3_1_fop_prog.progname, glusterfs3_1_fop_prog.prognum, @@ -743,7 +741,7 @@ init (xlator_t *this) gluster_handshake_prog.options = this->options; ret = rpcsvc_program_register (conf->rpc, &gluster_handshake_prog); if (ret) { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_WARNING, "registration of program (name:%s, prognum:%d, " "progver:%d) failed", gluster_handshake_prog.progname, gluster_handshake_prog.prognum, diff --git a/xlators/protocol/server/src/server3_1-fops.c b/xlators/protocol/server/src/server3_1-fops.c index 43f7c82d428..2d1e9d0391a 100644 --- a/xlators/protocol/server/src/server3_1-fops.c +++ b/xlators/protocol/server/src/server3_1-fops.c @@ -47,6 +47,10 @@ server_statfs_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret >= 0) { gf_statfs_from_statfs (&rsp.statfs, buf); + } else { + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": STATFS %"PRId32" (%s)", + frame->root->unique, op_ret, strerror (op_errno)); } server_submit_reply (frame, req, &rsp, NULL, 0, NULL, @@ -66,9 +70,9 @@ server_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this, inode_t *root_inode = NULL; inode_t *link_inode = NULL; loc_t fresh_loc = {0,}; - gfs3_lookup_rsp rsp = {0, }; + gfs3_lookup_rsp rsp = {0,}; int32_t ret = -1; - uuid_t rootgfid = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1}; + uuid_t rootgfid = {0,}; state = CALL_STATE(frame); @@ -128,6 +132,7 @@ server_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (inode == root_inode) { /* we just looked up root ("/") */ stbuf->ia_ino = 1; + rootgfid[15] = 1; uuid_copy (stbuf->ia_gfid, rootgfid); if (inode->ia_type == 0) inode->ia_type = stbuf->ia_type; @@ -149,17 +154,19 @@ server_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this, state->loc.name); } } + } +out: + rsp.op_ret = op_ret; + rsp.op_errno = gf_errno_to_error (op_errno); + if (op_ret) { gf_log (this->name, - (op_errno == ENOENT ? GF_LOG_TRACE : GF_LOG_DEBUG), + (op_errno == ENOENT ? GF_LOG_TRACE : GF_LOG_INFO), "%"PRId64": LOOKUP %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, op_ret, strerror (op_errno)); } -out: - rsp.op_ret = op_ret; - rsp.op_errno = gf_errno_to_error (op_errno); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, (gfs_serialize_t)xdr_serialize_lookup_rsp); @@ -205,7 +212,7 @@ server_lk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_proto_flock_from_flock (&rsp.flock, lock); } else if (op_errno != ENOSYS) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": LK %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -245,7 +252,7 @@ server_inodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, &state->loc, NULL, frame->root->pid, frame->root->lk_owner, GF_FOP_INODELK); } else if (op_errno != ENOSYS) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": INODELK %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, op_ret, @@ -287,7 +294,7 @@ server_finodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, frame->root->pid, frame->root->lk_owner, GF_FOP_INODELK); } else if (op_errno != ENOSYS) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FINODELK %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -326,7 +333,7 @@ server_entrylk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, &state->loc, NULL, frame->root->pid, frame->root->lk_owner, GF_FOP_ENTRYLK); } else if (op_errno != ENOSYS) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": INODELK %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, op_ret, @@ -364,7 +371,7 @@ server_fentrylk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, NULL, state->fd, frame->root->pid, frame->root->lk_owner, GF_FOP_ENTRYLK); } else if (op_errno != ENOSYS) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FENTRYLK %"PRId64" (%"PRId64") " " ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, @@ -385,11 +392,20 @@ server_access_cbk (call_frame_t *frame, void *cookie, xlator_t *this, { gf_common_rsp rsp = {0,}; rpcsvc_request_t *req = NULL; + server_state_t *state = NULL; req = frame->local; + state = CALL_STATE(frame); + rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); + if (op_ret) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": ACCESS %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_common_rsp); @@ -426,7 +442,7 @@ server_rmdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.preparent, preparent); gf_stat_from_iatt (&rsp.postparent, postparent); } else { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": RMDIR %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -466,7 +482,7 @@ server_mkdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, inode_lookup (link_inode); inode_unref (link_inode); } else { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": MKDIR %s ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, op_ret, strerror (op_errno)); @@ -505,7 +521,7 @@ server_mknod_cbk (call_frame_t *frame, void *cookie, xlator_t *this, inode_lookup (link_inode); inode_unref (link_inode); } else { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": MKNOD %s ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, op_ret, strerror (op_errno)); @@ -534,7 +550,7 @@ server_fsyncdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, state = CALL_STATE(frame); if (op_ret < 0) { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FSYNCDIR %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -567,7 +583,7 @@ server_readdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, goto unwind; } } else { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": READDIR %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -623,7 +639,7 @@ server_opendir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, fd_no = gf_fd_unused_get (conn->fdtable, fd); fd_ref (fd); // on behalf of the client } else { - gf_log (this->name, GF_LOG_TRACE, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": OPENDIR %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -648,11 +664,19 @@ server_removexattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, { gf_common_rsp rsp = {0,}; rpcsvc_request_t *req = NULL; + server_state_t *state = NULL; - req = frame->local; + req = frame->local; + state = CALL_STATE(frame); rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": REMOVEXATTR %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_common_rsp); @@ -709,6 +733,12 @@ out: rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); rsp.dict.dict_len = len; + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": GETXATTR %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_getxattr_rsp); @@ -768,6 +798,13 @@ out: rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); rsp.dict.dict_len = len; + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": FGETXATTR %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->resolve.fd_no, + state->fd ? state->fd->inode->ino : 0, op_ret, + strerror (op_errno)); + server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_fgetxattr_rsp); @@ -783,12 +820,20 @@ server_setxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, { gf_common_rsp rsp = {0,}; rpcsvc_request_t *req = NULL; + server_state_t *state = NULL; req = frame->local; + state = CALL_STATE(frame); rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": SETXATTR %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_common_rsp); @@ -802,12 +847,21 @@ server_fsetxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, { gf_common_rsp rsp = {0,}; rpcsvc_request_t *req = NULL; + server_state_t *state = NULL; req = frame->local; + state = CALL_STATE(frame); rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": FSETXATTR %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->resolve.fd_no, + state->fd ? state->fd->inode->ino : 0, op_ret, + strerror (op_errno)); + server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_common_rsp); @@ -855,6 +909,13 @@ server_rename_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.postnewparent, postnewparent); } + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": RENAME %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); + server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_rename_rsp); @@ -897,7 +958,7 @@ server_unlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.postparent, postparent); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": UNLINK %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -937,7 +998,7 @@ server_symlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, inode_lookup (link_inode); inode_unref (link_inode); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": SYMLINK %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -982,6 +1043,13 @@ server_link_cbk (call_frame_t *frame, void *cookie, xlator_t *this, inode_unref (link_inode); } + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": LINK %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); + server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_link_rsp); @@ -1008,7 +1076,7 @@ server_truncate_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.prestat, prebuf); gf_stat_from_iatt (&rsp.poststat, postbuf); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": TRUNCATE %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1039,7 +1107,7 @@ server_fstat_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret == 0) { gf_stat_from_iatt (&rsp.stat, stbuf); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FSTAT %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -1072,7 +1140,7 @@ server_ftruncate_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.prestat, prebuf); gf_stat_from_iatt (&rsp.poststat, postbuf); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FTRUNCATE %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -1100,7 +1168,7 @@ server_flush_cbk (call_frame_t *frame, void *cookie, xlator_t *this, state = CALL_STATE(frame); if (op_ret < 0) { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FLUSH %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -1130,15 +1198,15 @@ server_fsync_cbk (call_frame_t *frame, void *cookie, xlator_t *this, state = CALL_STATE(frame); - if (op_ret < 0) { - gf_log (this->name, GF_LOG_DEBUG, + if (op_ret >= 0) { + gf_stat_from_iatt (&(rsp.prestat), prebuf); + gf_stat_from_iatt (&(rsp.poststat), postbuf); + } else { + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FSYNC %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, strerror (op_errno)); - } else { - gf_stat_from_iatt (&(rsp.prestat), prebuf); - gf_stat_from_iatt (&(rsp.poststat), postbuf); } server_submit_reply (frame, req, &rsp, NULL, 0, NULL, @@ -1147,24 +1215,6 @@ server_fsync_cbk (call_frame_t *frame, void *cookie, xlator_t *this, return 0; } -int -server_release_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno) -{ - gf_common_rsp rsp = {0,}; - rpcsvc_request_t *req = NULL; - - req = frame->local; - - rsp.op_ret = op_ret; - rsp.op_errno = gf_errno_to_error (op_errno); - - server_submit_reply (frame, req, &rsp, NULL, 0, NULL, - xdr_serialize_common_rsp); - return 0; -} - - int server_writev_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *prebuf, @@ -1184,7 +1234,7 @@ server_writev_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.prestat, prebuf); gf_stat_from_iatt (&rsp.poststat, postbuf); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": WRITEV %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -1218,7 +1268,7 @@ server_readv_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.stat, stbuf); rsp.size = op_ret; } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": READV %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, state->fd ? state->fd->inode->ino : 0, op_ret, @@ -1238,9 +1288,11 @@ server_rchecksum_cbk (call_frame_t *frame, void *cookie, xlator_t *this, { gfs3_rchecksum_rsp rsp = {0,}; rpcsvc_request_t *req = NULL; + server_state_t *state = NULL; req = frame->local; + state = CALL_STATE(frame); rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); @@ -1250,6 +1302,12 @@ server_rchecksum_cbk (call_frame_t *frame, void *cookie, xlator_t *this, rsp.strong_checksum.strong_checksum_val = (char *)strong_checksum; rsp.strong_checksum.strong_checksum_len = MD5_DIGEST_LEN; } + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": RCHECKSUM %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->resolve.fd_no, + state->fd ? state->fd->inode->ino : 0, op_ret, + strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_rchecksum_rsp); @@ -1276,7 +1334,7 @@ server_open_cbk (call_frame_t *frame, void *cookie, xlator_t *this, fd_no = gf_fd_unused_get (conn->fdtable, fd); fd_ref (fd); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": OPEN %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1353,7 +1411,7 @@ server_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.preparent, preparent); gf_stat_from_iatt (&rsp.postparent, postparent); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": CREATE %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1394,7 +1452,7 @@ server_readlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.buf, stbuf); rsp.path = (char *)buf; } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": READLINK %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1428,7 +1486,7 @@ server_stat_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret == 0) { gf_stat_from_iatt (&rsp.stat, stbuf); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": STAT %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1462,7 +1520,7 @@ server_setattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.statpre, statpre); gf_stat_from_iatt (&rsp.statpost, statpost); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": SETATTR %s (%"PRId64") ==> %"PRId32" (%s)", frame->root->unique, state->loc.path, state->loc.inode ? state->loc.inode->ino : 0, @@ -1490,7 +1548,7 @@ server_fsetattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, gf_stat_from_iatt (&rsp.statpre, statpre); gf_stat_from_iatt (&rsp.statpost, statpost); } else { - gf_log (this->name, GF_LOG_DEBUG, + gf_log (this->name, GF_LOG_INFO, "%"PRId64": FSETATTR %"PRId64" (%"PRId64") ==> " "%"PRId32" (%s)", frame->root->unique, state->resolve.fd_no, @@ -1566,6 +1624,12 @@ out: rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); rsp.dict.dict_len = len; + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": XATTROP %s (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->loc.path, + state->loc.inode ? state->loc.inode->ino : 0, + op_ret, strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_xattrop_rsp); @@ -1634,6 +1698,12 @@ out: rsp.op_ret = op_ret; rsp.op_errno = gf_errno_to_error (op_errno); rsp.dict.dict_len = len; + if (op_ret == -1) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": FXATTROP %"PRId64" (%"PRId64") ==> %"PRId32" (%s)", + frame->root->unique, state->resolve.fd_no, + state->fd ? state->fd->inode->ino : 0, op_ret, + strerror (op_errno)); server_submit_reply (frame, req, &rsp, NULL, 0, NULL, xdr_serialize_fxattrop_rsp); @@ -1665,12 +1735,13 @@ server_readdirp_cbk (call_frame_t *frame, void *cookie, xlator_t *this, goto out; } } else { - gf_log (this->name, GF_LOG_TRACE, - "%"PRId64": READDIRP %"PRId64" (%"PRId64") ==>" - "%"PRId32" (%s)", - frame->root->unique, state->resolve.fd_no, - state->fd ? state->fd->inode->ino : 0, op_ret, - strerror (op_errno)); + if (op_errno != ENOENT) + gf_log (this->name, GF_LOG_INFO, + "%"PRId64": READDIRP %"PRId64" (%"PRId64") ==>" + "%"PRId32" (%s)", + frame->root->unique, state->resolve.fd_no, + state->fd ? state->fd->inode->ino : 0, op_ret, + strerror (op_errno)); } out: @@ -2828,8 +2899,6 @@ server_create (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (state->conn->bound_xl->name, GF_LOG_ERROR, - "out of memory"); goto out; } @@ -4078,8 +4147,6 @@ server_mknod (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (state->conn->bound_xl->name, GF_LOG_ERROR, - "out of memory"); goto out; } @@ -4178,8 +4245,6 @@ server_mkdir (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (state->conn->bound_xl->name, GF_LOG_ERROR, - "out of memory"); goto out; } @@ -4626,8 +4691,6 @@ server_symlink (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (state->conn->bound_xl->name, GF_LOG_ERROR, - "out of memory"); goto out; } @@ -4994,8 +5057,6 @@ server_lookup (rpcsvc_request_t *req) buf = memdup (args.dict.dict_val, args.dict.dict_len); if (buf == NULL) { - gf_log (conn->bound_xl->name, GF_LOG_ERROR, - "out of memory"); goto out; } -- cgit