summaryrefslogtreecommitdiffstats
path: root/xlators/protocol/server
diff options
context:
space:
mode:
authorAnand Avati <avati@gluster.com>2009-11-29 07:45:20 +0000
committerAnand V. Avati <avati@dev.gluster.com>2009-11-29 05:33:02 -0800
commit6c949d9d0ddc3397eac3207c0718743d49bd8707 (patch)
tree27eb25cd103783dac420beefe9d293a83e2a8562 /xlators/protocol/server
parent77a7250b16c119e20c2d5c66a80b559455953a47 (diff)
protocol/server: enhance trace logging
add logging of fop name, callid number and make logging more friendly Signed-off-by: Anand V. Avati <avati@blackhole.gluster.com> Signed-off-by: Anand V. Avati <avati@dev.gluster.com> BUG: 315 (generation number support) URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=315
Diffstat (limited to 'xlators/protocol/server')
-rw-r--r--xlators/protocol/server/src/server-helpers.h2
-rw-r--r--xlators/protocol/server/src/server-protocol.c280
-rw-r--r--xlators/protocol/server/src/server-resolve.c9
3 files changed, 206 insertions, 85 deletions
diff --git a/xlators/protocol/server/src/server-helpers.h b/xlators/protocol/server/src/server-helpers.h
index de5b84de840..867035d3334 100644
--- a/xlators/protocol/server/src/server-helpers.h
+++ b/xlators/protocol/server/src/server-helpers.h
@@ -67,6 +67,6 @@ int32_t
gf_direntry_to_bin (dir_entry_t *head, char *bufferp);
void
-print_server_state (call_frame_t *frame, server_state_t *state, xlator_t *this, int request);
+server_print_request (call_frame_t *frame);
#endif /* __SERVER_HELPERS_H__ */
diff --git a/xlators/protocol/server/src/server-protocol.c b/xlators/protocol/server/src/server-protocol.c
index 9fc9adf14c7..b7b64476518 100644
--- a/xlators/protocol/server/src/server-protocol.c
+++ b/xlators/protocol/server/src/server-protocol.c
@@ -43,8 +43,28 @@
#include "statedump.h"
#include "md5.h"
+
void
-print_resolve_vars (char *str, int size, server_resolve_t *resolve)
+print_caller (char *str, int size, call_frame_t *frame)
+{
+ int filled = 0;
+ server_state_t *state = NULL;
+ transport_t *trans = NULL;
+
+ state = CALL_STATE (frame);
+ trans = state->trans;
+
+ filled += snprintf (str + filled, size - filled,
+ " Callid=%"PRId64", Client=%s",
+ frame->root->unique,
+ trans->peerinfo.identifier);
+
+ return;
+}
+
+
+void
+server_print_resolve (char *str, int size, server_resolve_t *resolve)
{
int filled = 0;
@@ -53,29 +73,33 @@ print_resolve_vars (char *str, int size, server_resolve_t *resolve)
return;
}
- if (resolve->fd_no)
- filled += snprintf (str + filled, size - filled, "fd_no: %"PRId64" ", resolve->fd_no);
+ filled += snprintf (str + filled, size - filled,
+ " Resolve={");
+ if (resolve->fd_no != -1)
+ filled += snprintf (str + filled, size - filled,
+ "fd=%"PRId64",", (uint64_t) resolve->fd_no);
if (resolve->ino)
- filled += snprintf (str + filled, size - filled, "ino: %llu ",
- (unsigned long long) resolve->ino);
- if (resolve->gen)
- filled += snprintf (str + filled, size - filled, "gen: %"PRIu64" ", resolve->gen);
+ filled += snprintf (str + filled, size - filled,
+ "ino=%"PRIu64",", (uint64_t) resolve->ino);
if (resolve->par)
- filled += snprintf (str + filled, size - filled, "par: %llu ",
- (unsigned long long) resolve->par);
- if (resolve->path)
- filled += snprintf (str + filled, size - filled, "path: %s ", resolve->path);
+ filled += snprintf (str + filled, size - filled,
+ "par=%"PRIu64",", (uint64_t) resolve->par);
+ if (resolve->gen)
+ filled += snprintf (str + filled, size - filled,
+ "gen=%"PRIu64",", (uint64_t) resolve->gen);
if (resolve->bname)
- filled += snprintf (str + filled, size - filled, "bname: %s ", resolve->bname);
- if (resolve->resolved)
- filled += snprintf (str + filled, size - filled, "resolved: %s ", resolve->resolved);
- if (resolve->comp_count)
- filled += snprintf (str + filled, size - filled, "comp_count: %d ", resolve->comp_count);
+ filled += snprintf (str + filled, size - filled,
+ "bname=%s,", resolve->bname);
+ if (resolve->path)
+ filled += snprintf (str + filled, size - filled,
+ "path=%s", resolve->path);
+ filled += snprintf (str + filled, size - filled, "}");
}
+
void
-print_loc_vars (char *str, int size, loc_t *loc)
+server_print_loc (char *str, int size, loc_t *loc)
{
int filled = 0;
@@ -84,103 +108,204 @@ print_loc_vars (char *str, int size, loc_t *loc)
return;
}
- if (loc->path)
- filled += snprintf (str + filled, size - filled, "path: %s ", loc->path);
- if (loc->name)
- snprintf (str + filled, size - filled, "name: %s ", loc->name);
- if (loc->ino)
- snprintf (str + filled, size - filled, "ino: %llu ",
- (unsigned long long) loc->ino);
+ filled += snprintf (str + filled, size - filled,
+ " Loc={");
+ if (loc->path)
+ filled += snprintf (str + filled, size - filled,
+ "path=%s,", loc->path);
+ if (loc->inode)
+ filled += snprintf (str + filled, size - filled,
+ "inode=%p,", loc->inode);
+ if (loc->parent)
+ filled += snprintf (str + filled, size - filled,
+ "parent=%p", loc->parent);
+ filled += snprintf (str + filled, size - filled, "}");
}
+
void
-print_state_vars (char *str, int size, server_state_t *state)
+server_print_params (char *str, int size, server_state_t *state)
{
int filled = 0;
- if (state->trans)
- filled = snprintf (str + filled, size - filled, "transport: %p ", state->trans);
- if (state->bound_xl)
- filled += snprintf (str + filled, size - filled, "xlator: %s ",state->bound_xl->name);
+ filled += snprintf (str + filled, size - filled,
+ " Params={");
+
+ if (state->fd)
+ filled += snprintf (str + filled, size - filled,
+ "fd=%p,", state->fd);
if (state->valid)
- filled += snprintf (str + filled, size - filled, "valid: %d ", state->valid);
+ filled += snprintf (str + filled, size - filled,
+ "valid=%d,", state->valid);
if (state->flags)
- filled += snprintf (str + filled, size - filled, "flags: %d ", state->flags);
+ filled += snprintf (str + filled, size - filled,
+ "flags=%d,", state->flags);
if (state->wbflags)
- filled += snprintf (str + filled, size - filled, "wbflags: %d ", state->wbflags);
+ filled += snprintf (str + filled, size - filled,
+ "wbflags=%d,", state->wbflags);
if (state->size)
- filled += snprintf (str + filled, size - filled, "size: %Zu ", state->size);
+ filled += snprintf (str + filled, size - filled,
+ "size=%Zu,", state->size);
if (state->offset)
- filled += snprintf (str + filled, size - filled, "offset: %llu ",
- (unsigned long long) state->offset);
+ filled += snprintf (str + filled, size - filled,
+ "offset=%"PRId64",", state->offset);
if (state->cmd)
- filled += snprintf (str + filled, size - filled, "cmd: %d ", state->cmd);
+ filled += snprintf (str + filled, size - filled,
+ "cmd=%d,", state->cmd);
if (state->type)
- filled += snprintf (str + filled, size - filled, "type: %d ", state->type);
+ filled += snprintf (str + filled, size - filled,
+ "type=%d,", state->type);
if (state->name)
- filled += snprintf (str + filled, size - filled, "name: %s ", state->name);
+ filled += snprintf (str + filled, size - filled,
+ "name=%s,", state->name);
if (state->mask)
- filled += snprintf (str + filled, size - filled, "mask: %d ", state->mask);
+ filled += snprintf (str + filled, size - filled,
+ "mask=%d,", state->mask);
if (state->volume)
- filled += snprintf (str + filled, size - filled, "volume: %s ", state->volume);
+ filled += snprintf (str + filled, size - filled,
+ "volume=%s,", state->volume);
+ filled += snprintf (str + filled, size - filled,
+ "bound_xl=%s}", state->bound_xl->name);
}
-void
-print_server_state (call_frame_t *frame, server_state_t *state, xlator_t *this, int request)
+
+int
+server_resolve_is_empty (server_resolve_t *resolve)
{
- server_conf_t *conf = NULL;
- char resolve_vars[256];
- char resolve2_vars[256];
- char loc_vars[256];
- char loc2_vars[256];
- char other_vars[512];
+ if (resolve->fd_no != -1)
+ return 0;
- memset (resolve_vars, '\0', 256);
- memset (resolve2_vars, '\0', 256);
- memset (loc_vars, '\0', 256);
- memset (loc2_vars, '\0', 256);
- memset (other_vars, '\0', 512);
+ if (resolve->ino != 0)
+ return 0;
+
+ if (resolve->gen != 0)
+ return 0;
+
+ if (resolve->par != 0)
+ return 0;
+
+ if (resolve->path != 0)
+ return 0;
+
+ if (resolve->bname != 0)
+ return 0;
+
+ return 1;
+}
+
+
+void
+server_print_reply (call_frame_t *frame, int op_ret, int op_errno)
+{
+ server_conf_t *conf = NULL;
+ server_state_t *state = NULL;
+ xlator_t *this = NULL;
+ char caller[512];
+ char fdstr[32];
+ char *op = "UNKNOWN";
+ this = frame->this;
conf = this->private;
+
if (!conf->trace)
return;
- if (request) {
+ state = CALL_STATE (frame);
- print_resolve_vars (resolve_vars, 256, &state->resolve);
- print_resolve_vars (resolve2_vars, 256, &state->resolve2);
+ print_caller (caller, 256, frame);
- print_loc_vars (loc_vars, 256, &state->loc);
- print_loc_vars (loc2_vars, 256, &state->loc2);
+ switch (frame->root->type) {
+ case GF_OP_TYPE_FOP_REQUEST:
+ case GF_OP_TYPE_FOP_REPLY:
+ op = gf_fop_list[frame->root->op];
+ break;
+ case GF_OP_TYPE_MOP_REQUEST:
+ case GF_OP_TYPE_MOP_REPLY:
+ op = gf_mop_list[frame->root->op];
+ break;
+ case GF_OP_TYPE_CBK_REQUEST:
+ case GF_OP_TYPE_CBK_REPLY:
+ op = gf_cbk_list[frame->root->op];
+ break;
+ }
- print_state_vars (other_vars, 512, state);
+ fdstr[0] = '\0';
+ if (state->fd)
+ snprintf (fdstr, 128, " fd=%p", state->fd);
- gf_log (this->name, GF_LOG_NORMAL,
- "[REQUEST] resolve = {%s} resolve2 = {%s} loc = {%s}"
- " loc2 = {%s} State Vars = {%s}",
- strlen (resolve_vars) ? resolve_vars : "<nul>",
- strlen (resolve2_vars) ? resolve2_vars : "<nul>",
- strlen (loc_vars) ? loc_vars : "<nul>",
- strlen (loc2_vars) ? loc2_vars : "<nul>",
- strlen (other_vars) ? other_vars : "<nul>"
- );
- } else {
+ gf_log (this->name, GF_LOG_NORMAL,
+ "%s%s => (%d, %d)%s",
+ op, caller, op_ret, op_errno, fdstr);
+}
+
+
+void
+server_print_request (call_frame_t *frame)
+{
+ server_conf_t *conf = NULL;
+ xlator_t *this = NULL;
+ server_state_t *state = NULL;
+ char resolve_vars[256];
+ char resolve2_vars[256];
+ char loc_vars[256];
+ char loc2_vars[256];
+ char other_vars[512];
+ char caller[512];
+ char *op = "UNKNOWN";
+
+ this = frame->this;
+ conf = this->private;
+
+ state = CALL_STATE (frame);
+
+ if (!conf->trace)
+ return;
- print_loc_vars (loc_vars, 256, &state->loc);
- print_state_vars (other_vars, 512, state);
+ memset (resolve_vars, '\0', 256);
+ memset (resolve2_vars, '\0', 256);
+ memset (loc_vars, '\0', 256);
+ memset (loc2_vars, '\0', 256);
+ memset (other_vars, '\0', 256);
+
+ print_caller (caller, 256, frame);
+
+ if (!server_resolve_is_empty (&state->resolve)) {
+ server_print_resolve (resolve_vars, 256, &state->resolve);
+ server_print_loc (loc_vars, 256, &state->loc);
+ }
- gf_log (this->name, GF_LOG_NORMAL,
- "[REPLY] loc = {%s} State Vars = {%s}",
- strlen (loc_vars) ? loc_vars : "<nul>",
- strlen (other_vars) ? other_vars : "<nul>"
- );
+ if (!server_resolve_is_empty (&state->resolve2)) {
+ server_print_resolve (resolve2_vars, 256, &state->resolve2);
+ server_print_loc (loc2_vars, 256, &state->loc2);
}
+ server_print_params (other_vars, 512, state);
+
+ switch (frame->root->type) {
+ case GF_OP_TYPE_FOP_REQUEST:
+ case GF_OP_TYPE_FOP_REPLY:
+ op = gf_fop_list[frame->root->op];
+ break;
+ case GF_OP_TYPE_MOP_REQUEST:
+ case GF_OP_TYPE_MOP_REPLY:
+ op = gf_mop_list[frame->root->op];
+ break;
+ case GF_OP_TYPE_CBK_REQUEST:
+ case GF_OP_TYPE_CBK_REPLY:
+ op = gf_cbk_list[frame->root->op];
+ break;
+ }
+
+ gf_log (this->name, GF_LOG_NORMAL,
+ "%s%s%s%s%s%s%s",
+ gf_fop_list[frame->root->op], caller,
+ resolve_vars, loc_vars, resolve2_vars, loc2_vars, other_vars);
}
+
static void
protocol_server_reply (call_frame_t *frame, int type, int op,
gf_hdr_common_t *hdr, size_t hdrlen,
@@ -203,7 +328,8 @@ protocol_server_reply (call_frame_t *frame, int type, int op,
hdr->type = hton32 (type);
hdr->op = hton32 (op);
- print_server_state (frame, state, this, 0);
+ server_print_reply (frame, ntoh32 (hdr->rsp.op_ret),
+ gf_error_to_errno (ntoh32 (hdr->rsp.op_errno)));
ret = transport_submit (trans, (char *)hdr, hdrlen, vector,
count, iobref);
diff --git a/xlators/protocol/server/src/server-resolve.c b/xlators/protocol/server/src/server-resolve.c
index f7a2205e588..0db29468ffd 100644
--- a/xlators/protocol/server/src/server-resolve.c
+++ b/xlators/protocol/server/src/server-resolve.c
@@ -524,6 +524,8 @@ server_resolve_done (call_frame_t *frame)
state = CALL_STATE (frame);
bound_xl = BOUND_XL (frame);
+ server_print_request (frame);
+
state->resume_fn (frame, bound_xl);
return 0;
@@ -581,13 +583,6 @@ resolve_and_resume (call_frame_t *frame, server_resume_fn_t fn)
this = frame->this;
- gf_log (BOUND_XL (frame)->name, GF_LOG_DEBUG,
- "RESOLVE %s() on %s %s",
- gf_fop_list[frame->root->op],
- state->resolve.path, state->resolve2.path);
-
- print_server_state (frame, state, this, 1);
-
server_resolve_all (frame);
return 0;