diff options
author | Raghavendra Talur <rtalur@redhat.com> | 2016-02-15 18:16:04 +0530 |
---|---|---|
committer | Vijay Bellur <vbellur@redhat.com> | 2016-04-27 12:26:31 -0700 |
commit | c4d67a8338b42d6485f49999f310cbb9ed5359c5 (patch) | |
tree | d5896e698878f6f5630d08f85b52b77b853271a2 /libglusterfs | |
parent | 302e218f68ef5edab6b369411d6f06cafea08ce1 (diff) |
libglusterfs: Add debug and trace logs for stack trace
It has become very difficult to identify the xlator which returned
negative op_ret. Being able to just change the log level and
visualize the stack is helpful in such cases.
Change-Id: I6545b4802c1ab4d0d230d5e9e036afb2384882e1
BUG: 1330052
Signed-off-by: Raghavendra Talur <rtalur@redhat.com>
Reviewed-on: http://review.gluster.org/13448
CentOS-regression: Gluster Build System <jenkins@build.gluster.com>
NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
Smoke: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Jeff Darcy <jdarcy@redhat.com>
Reviewed-by: Rajesh Joseph <rjoseph@redhat.com>
Reviewed-by: Vijay Bellur <vbellur@redhat.com>
Diffstat (limited to 'libglusterfs')
-rw-r--r-- | libglusterfs/src/stack.h | 53 |
1 files changed, 49 insertions, 4 deletions
diff --git a/libglusterfs/src/stack.h b/libglusterfs/src/stack.h index 43d943c62b6..2899be9bf2f 100644 --- a/libglusterfs/src/stack.h +++ b/libglusterfs/src/stack.h @@ -259,6 +259,11 @@ STACK_RESET (call_stack_t *stack) UNLOCK(&frame->root->stack_lock); \ old_THIS = THIS; \ THIS = obj; \ + gf_msg_trace ("stack-trace", 0, \ + "stack-address: %p, " \ + "winding from %s to %s", \ + frame->root, old_THIS->name, \ + THIS->name); \ if (frame->this->ctx->measure_latency) \ gf_latency_begin (_new, fn); \ fn (_new, obj, params); \ @@ -275,6 +280,11 @@ STACK_RESET (call_stack_t *stack) frame->wind_to = #fn; \ old_THIS = THIS; \ THIS = obj; \ + gf_msg_trace ("stack-trace", 0, \ + "stack-address: %p, " \ + "winding from %s to %s", \ + frame->root, old_THIS->name, \ + THIS->name); \ fn (frame, obj, params); \ THIS = old_THIS; \ } while (0) @@ -309,6 +319,11 @@ STACK_RESET (call_stack_t *stack) fn##_cbk = rfn; \ old_THIS = THIS; \ THIS = obj; \ + gf_msg_trace ("stack-trace", 0, \ + "stack-address: %p, " \ + "winding from %s to %s", \ + frame->root, old_THIS->name, \ + THIS->name); \ if (obj->ctx->measure_latency) \ gf_latency_begin (_new, fn); \ fn (_new, obj, params); \ @@ -317,7 +332,7 @@ STACK_RESET (call_stack_t *stack) /* return from function */ -#define STACK_UNWIND(frame, params ...) \ +#define STACK_UNWIND(frame, op_ret, op_errno, params ...) \ do { \ ret_fn_t fn = NULL; \ call_frame_t *_parent = NULL; \ @@ -327,6 +342,20 @@ STACK_RESET (call_stack_t *stack) LG_MSG_FRAME_ERROR, "!frame"); \ break; \ } \ + if (op_ret < 0) { \ + gf_msg_debug ("stack-trace", op_errno, \ + "stack-address: %p, " \ + "%s returned %d error: %s", \ + frame->root, THIS->name, \ + (int32_t)op_ret, \ + strerror(op_errno)); \ + } else { \ + gf_msg_trace ("stack-trace", 0, \ + "stack-address: %p, " \ + "%s returned %d", \ + frame->root, THIS->name, \ + (int32_t)op_ret); \ + } \ fn = frame->ret; \ _parent = frame->parent; \ LOCK(&frame->root->stack_lock); \ @@ -340,13 +369,14 @@ STACK_RESET (call_stack_t *stack) frame->unwind_from = __FUNCTION__; \ if (frame->this->ctx->measure_latency) \ gf_latency_end (frame); \ - fn (_parent, frame->cookie, _parent->this, params); \ + fn (_parent, frame->cookie, _parent->this, op_ret, \ + op_errno, params); \ THIS = old_THIS; \ } while (0) /* return from function in type-safe way */ -#define STACK_UNWIND_STRICT(op, frame, params ...) \ +#define STACK_UNWIND_STRICT(op, frame, op_ret, op_errno, params ...) \ do { \ fop_##op##_cbk_t fn = NULL; \ call_frame_t *_parent = NULL; \ @@ -357,6 +387,20 @@ STACK_RESET (call_stack_t *stack) LG_MSG_FRAME_ERROR, "!frame"); \ break; \ } \ + if (op_ret < 0) { \ + gf_msg_debug ("stack-trace", op_errno, \ + "stack-address: %p, " \ + "%s returned %d error: %s", \ + frame->root, THIS->name, \ + (int32_t)op_ret, \ + strerror(op_errno)); \ + } else { \ + gf_msg_trace ("stack-trace", 0, \ + "stack-address: %p, " \ + "%s returned %d", \ + frame->root, THIS->name, \ + (int32_t)op_ret); \ + } \ fn = (fop_##op##_cbk_t )frame->ret; \ _parent = frame->parent; \ LOCK(&frame->root->stack_lock); \ @@ -370,7 +414,8 @@ STACK_RESET (call_stack_t *stack) frame->unwind_from = __FUNCTION__; \ if (frame->this->ctx->measure_latency) \ gf_latency_end (frame); \ - fn (_parent, frame->cookie, _parent->this, params); \ + fn (_parent, frame->cookie, _parent->this, op_ret, \ + op_errno, params); \ THIS = old_THIS; \ } while (0) |