[Sheepdog] [PATCH v2 07/13] trace: add graph tracer

[Liu Yuan]

From: Liu Yuan <tailai.ly at taobao.com>

- add return hooker

Signed-off-by: Liu Yuan <tailai.ly at taobao.com>
---
 include/sheep.h      |   14 +++++++
 sheep/trace/graph.c  |  105 ++++++++++++++++++++++++++++++++++++++++++++++++++
 sheep/trace/mcount.S |   16 +++++++-
 sheep/trace/trace.h  |   10 +++++
 4 files changed, 144 insertions(+), 1 deletions(-)
 create mode 100644 sheep/trace/graph.c

diff --git a/include/sheep.h b/include/sheep.h
index fc86c25..30619b8 100644
--- a/include/sheep.h
+++ b/include/sheep.h
@@ -162,6 +162,20 @@ struct epoch_log {
 	struct sd_node nodes[SD_MAX_NODES];
 };
 
+#define TRACE_GRAPH_ENTRY  0x01
+#define TRACE_GRAPH_RETURN 0x02
+
+#define TRACE_BUF_LEN      1024 * 1024 * 8
+#define TRACE_FNAME_LEN    36
+
+struct trace_graph_item {
+	int type;
+	char fname[TRACE_FNAME_LEN];
+	int depth;
+	unsigned long long entry_time;
+	unsigned long long return_time;
+};
+
 static inline int same_node(struct sd_vnode *e, int n1, int n2)
 {
 	if (memcmp(e[n1].addr, e[n2].addr, sizeof(e->addr)) == 0 &&
diff --git a/sheep/trace/graph.c b/sheep/trace/graph.c
new file mode 100644
index 0000000..7dfafc8
--- /dev/null
+++ b/sheep/trace/graph.c
@@ -0,0 +1,105 @@
+#include <time.h>
+#include <assert.h>
+
+#include "trace.h"
+#include "logger.h"
+#include "util.h"
+
+static __thread unsigned ret_stack_index;
+static __thread struct trace_ret_stack {
+	unsigned long ret;
+	unsigned long func;
+	unsigned long long entry_time;
+} trace_ret_stack[100]; /* FIXME: consider stack overrun */
+
+static void push_return_trace(unsigned long ret, unsigned long long etime,
+		unsigned long func, int *depth)
+{
+	trace_ret_stack[ret_stack_index].ret = ret;
+	trace_ret_stack[ret_stack_index].func = func;
+	trace_ret_stack[ret_stack_index].entry_time = etime;
+	*depth = ret_stack_index;
+	ret_stack_index++;
+}
+
+static void pop_return_trace(struct trace_graph_item *trace, unsigned long *ret_func)
+{
+	struct caller *cr;
+	unsigned long ip = trace_ret_stack[ret_stack_index].func;
+
+	cr = trace_lookup_ip(ip, 0);
+	assert(cr->namelen + 1 < TRACE_FNAME_LEN);
+	memcpy(trace->fname, cr->name, cr->namelen);
+	memset(trace->fname + cr->namelen, '\0', 1);
+
+	ret_stack_index--;
+	trace->entry_time = trace_ret_stack[ret_stack_index].entry_time;
+	*ret_func = trace_ret_stack[ret_stack_index].ret;
+	trace->depth = ret_stack_index;
+}
+
+static notrace uint64_t clock_get_time(void)
+{
+	struct timespec ts;
+
+	clock_gettime(CLOCK_REALTIME, &ts);
+	return (uint64_t)ts.tv_sec * 1000000000LL + (uint64_t)ts.tv_nsec;
+}
+
+static notrace void default_trace_graph_entry(struct trace_graph_item *item)
+{
+	rbuffer_push(&rbuf, item);
+}
+
+static notrace void default_trace_graph_return(struct trace_graph_item *item)
+{
+	rbuffer_push(&rbuf, item);
+}
+
+static trace_func_graph_ent_t trace_graph_entry = default_trace_graph_entry;
+static trace_func_graph_ret_t trace_graph_return = default_trace_graph_return;
+
+notrace unsigned long trace_return_call(void)
+{
+	struct trace_graph_item trace;
+	unsigned long ret;
+
+	trace.return_time = clock_get_time();
+	pop_return_trace(&trace, &ret);
+	trace.type = TRACE_GRAPH_RETURN;
+	trace_graph_return(&trace);
+
+	return ret;
+}
+
+notrace void trace_init_buffer(struct list_head *list)
+{
+	list_add(&rbuf.list, list);
+}
+
+/* Hook the return address and push it in the trace_ret_stack.
+ *
+ * ip: the address of the call instruction in the code.
+ * ret_addr: the address of return address in the stack frame.
+ */
+static notrace void graph_tracer(unsigned long ip, unsigned long *ret_addr)
+{
+	unsigned long old_addr = *ret_addr;
+	uint64_t entry_time;
+	struct trace_graph_item trace;
+	struct caller *cr;
+
+	cr = trace_lookup_ip(ip, 0);
+	assert(cr->namelen + 1 < TRACE_FNAME_LEN);
+	memcpy(trace.fname, cr->name, cr->namelen);
+	memset(trace.fname + cr->namelen, '\0', 1);
+
+	*ret_addr = (unsigned long)trace_return_caller;
+	entry_time = clock_get_time();
+	push_return_trace(old_addr, entry_time, ip, &trace.depth);
+	trace.type = TRACE_GRAPH_ENTRY;
+
+	trace_graph_entry(&trace);
+}
+
+register_tracer(graph_tracer);
diff --git a/sheep/trace/mcount.S b/sheep/trace/mcount.S
index 5f1e6b5..69c99ca 100644
--- a/sheep/trace/mcount.S
+++ b/sheep/trace/mcount.S
@@ -45,7 +45,7 @@ ENTRY(trace_caller)
 	movq %r9, 48(%rsp)
 
 	movq 0x38(%rsp), %rdi
-	movq 8(%rbp), %rsi
+	leaq 8(%rbp), %rsi
 	subq $INSN_SIZE, %rdi
 
 .globl trace_call
@@ -65,6 +65,20 @@ trace_call:
 trace_stub:
 	retq
 
+ENTRY(trace_return_caller)
+	subq  $24, %rsp
+
+	movq %rax, (%rsp)
+	movq %rdx, 8(%rsp)
+
+	call trace_return_call
+
+	movq %rax, %rdi
+	movq 8(%rsp), %rdx
+	movq (%rsp), %rax
+	addq $24, %rsp
+	jmp *%rdi
+
 .globl NOP5
 NOP5:
 	.byte 0x0f,0x1f,0x44,0x00,0x00 # Intel recommended one for 5 bytes nops
diff --git a/sheep/trace/trace.h b/sheep/trace/trace.h
index 5dcbca5..38ecd1b 100644
--- a/sheep/trace/trace.h
+++ b/sheep/trace/trace.h
@@ -6,6 +6,8 @@
 #ifndef __ASSEMBLY__
 #include <stdlib.h>
 
+#include "sheepdog_proto.h"
+#include "sheep.h"
 #include "list.h"
 #include "util.h"
 
@@ -27,6 +29,12 @@ struct caller {
 };
 
 typedef void (*trace_func_t)(unsigned long ip, unsigned long *parent_ip);
+/* Type of the callback handlers for function entry and return */
+typedef void (*trace_func_graph_ret_t)(struct trace_graph_item *);
+typedef void (*trace_func_graph_ent_t)(struct trace_graph_item *);
+
+/* graph.c */
+extern void trace_init_buffer(struct list_head *list);
 
 /* stabs.c */
 extern int get_ipinfo(unsigned long ip, struct ipinfo *info);
@@ -37,6 +45,8 @@ extern void mcount_call(void);
 extern void trace_caller(void);
 extern void trace_call(unsigned long, unsigned long *);
 extern const unsigned char NOP5[];
+extern void trace_return_caller(void);
+extern unsigned long trace_return_call(void);
 
 /* trace.c */
 extern pthread_cond_t trace_cond;
-- 
1.7.8.2