[Sheepdog] [PATCH v4 12/12] trace: support cat operation from collie

Liu Yuan namei.unix at gmail.com
Tue Apr 10 09:02:07 CEST 2012


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

usage:
after tracing the sheep, you can get a function graph:
  collie debug trace cat

- use per thread buffer, so no lock overhead
- every buffer has the size of 8M
- after trace buffer is catted, the buffer is reset, that is,
  you can not cat it again to get the output.

Signed-off-by: Liu Yuan <tailai.ly at taobao.com>
---
 collie/collie.h     |    7 ++++-
 collie/debug.c      |   72 +++++++++++++++++++++++++++++++++++++++++++++++++++
 configure.ac        |    2 +-
 include/sheep.h     |    1 +
 sheep/ops.c         |   14 ++++++++++
 sheep/sheep.c       |    1 +
 sheep/trace/graph.c |    2 +
 sheep/trace/trace.c |   30 +++++++++++++++++++++
 sheep/trace/trace.h |   26 +++++++++++++-----
 9 files changed, 146 insertions(+), 9 deletions(-)

diff --git a/collie/collie.h b/collie/collie.h
index 53cc48d..3a4ba69 100644
--- a/collie/collie.h
+++ b/collie/collie.h
@@ -73,6 +73,11 @@ int sd_write_object(uint64_t oid, uint64_t cow_oid, void *data, unsigned int dat
 extern struct command vdi_command;
 extern struct command node_command;
 extern struct command cluster_command;
-extern struct command debug_command;
+
+#ifdef ENABLE_TRACE
+  extern struct command debug_command;
+#else
+  #define debug_command {}
+#endif /* ENABLE_TRACE */
 
 #endif
diff --git a/collie/debug.c b/collie/debug.c
index 1c6ce9d..14f963f 100644
--- a/collie/debug.c
+++ b/collie/debug.c
@@ -2,6 +2,75 @@
 
 #include "collie.h"
 
+static void print_trace_item(struct trace_graph_item *item)
+{
+	int i;
+
+	if (item->type == TRACE_GRAPH_ENTRY) {
+		printf("             |  ");
+		for (i = 0; i < item->depth; i++)
+			printf("   ");
+		printf("%s() {\n", item->fname);
+	} else {
+		unsigned duration = item->return_time - item->entry_time;
+		unsigned quot = duration / 1000, rem = duration % 1000;
+		printf("%8u.%-3u |  ", quot, rem);
+		for (i = 0; i < item->depth; i++)
+			printf("   ");
+		printf("}\n");
+	}
+}
+
+static void parse_trace_buffer(char *buf, int size)
+{
+	struct trace_graph_item *item = (struct trace_graph_item *)buf;
+	int sz = size / sizeof(struct trace_graph_item), i;
+
+	printf("   Time(us)  |  Function Graph\n");
+	printf("-------------------------------\n");
+	for (i = 0; i < sz; i++)
+		print_trace_item(item++);
+	return;
+}
+
+static int do_trace_cat(void)
+{
+	int fd, ret;
+	struct sd_req hdr;
+	struct sd_rsp *rsp = (struct sd_rsp *)&hdr;
+	unsigned rlen, wlen;
+	char *buf = xzalloc(TRACE_BUF_LEN * 12);
+
+	fd = connect_to(sdhost, sdport);
+	if (fd < 0)
+		return EXIT_SYSFAIL;
+
+	memset(&hdr, 0, sizeof(hdr));
+	hdr.opcode = SD_OP_TRACE_CAT;
+	hdr.data_length = rlen = TRACE_BUF_LEN;
+	hdr.epoch = node_list_version;
+
+	wlen = 0;
+	ret = exec_req(fd, &hdr, buf, &wlen, &rlen);
+	close(fd);
+
+	if (ret) {
+		fprintf(stderr, "Failed to connect\n");
+		return EXIT_SYSFAIL;
+	}
+
+	if (rsp->result != SD_RES_SUCCESS) {
+		fprintf(stderr, "Trace failed: %s\n",
+				sd_strerror(rsp->result));
+		return EXIT_FAILURE;
+	}
+
+	parse_trace_buffer(buf, rlen);
+
+	free(buf);
+	return EXIT_SUCCESS;
+}
+
 static int debug_trace(int argc, char **argv)
 {
 	int fd, ret, i, l;
@@ -21,6 +90,9 @@ static int debug_trace(int argc, char **argv)
 	} else if (strcmp(cmd, "stop") == 0) {
 		enabled = 0;
 		printf("stop the tracing\n");
+	} else if (strcmp(cmd, "cat") == 0) {
+		printf("cat the tracing\n\n");
+		return do_trace_cat();
 	} else {
 		printf("unsupported operation\n");
 		return EXIT_FAILURE;
diff --git a/configure.ac b/configure.ac
index db7f043..7a5eedf 100644
--- a/configure.ac
+++ b/configure.ac
@@ -342,7 +342,7 @@ if test "x${enable_trace}" = xyes && \
 		cc_supports_flag -pg && \
 		cc_supports_flag -gstabs ; then
 	AC_MSG_NOTICE([Enabling trace (-pg -gstabs)])
-	TRACE_CFLAGS="-pg -gstabs"
+	TRACE_CFLAGS="-pg -gstabs -DENABLE_TRACE"
 	TRACE_LDFLAGS="-T$(pwd)/sheep/trace/trace.ld"
 	PACKAGE_FEATURES="$PACKAGE_FEATURES trace"
 else
diff --git a/include/sheep.h b/include/sheep.h
index 3362759..152d91d 100644
--- a/include/sheep.h
+++ b/include/sheep.h
@@ -44,6 +44,7 @@
 #define SD_OP_GET_SNAP_FILE  0x93
 #define SD_OP_CLEANUP        0x94
 #define SD_OP_TRACE          0x95
+#define SD_OP_TRACE_CAT      0x96
 
 #define SD_FLAG_CMD_IO_LOCAL   0x0010
 #define SD_FLAG_CMD_RECOVERY 0x0020
diff --git a/sheep/ops.c b/sheep/ops.c
index 20d114c..ee6dee1 100644
--- a/sheep/ops.c
+++ b/sheep/ops.c
@@ -530,6 +530,14 @@ static int local_trace_ops(const struct sd_req *req, struct sd_rsp *rsp, void *d
 	return ret;
 }
 
+static int local_trace_cat_ops(const struct sd_req *req, struct sd_rsp *rsp, void *data)
+{
+	rsp->data_length = trace_copy_buffer(data);
+	dprintf("%u\n", rsp->data_length);
+	trace_reset_buffer();
+	return SD_RES_SUCCESS;
+}
+
 static struct sd_op_template sd_ops[] = {
 
 	/* cluster operations */
@@ -661,6 +669,12 @@ static struct sd_op_template sd_ops[] = {
 		.process_main = local_trace_ops,
 	},
 
+	[SD_OP_TRACE_CAT] = {
+		.type = SD_OP_TYPE_LOCAL,
+		.force = 1,
+		.process_main = local_trace_cat_ops,
+	},
+
 	/* I/O operations */
 	[SD_OP_CREATE_AND_WRITE_OBJ] = {
 		.type = SD_OP_TYPE_IO,
diff --git a/sheep/sheep.c b/sheep/sheep.c
index 89e2d37..92f9760 100644
--- a/sheep/sheep.c
+++ b/sheep/sheep.c
@@ -234,6 +234,7 @@ int main(int argc, char **argv)
 	ret = trace_init();
 	if (ret)
 		exit(1);
+
 	vprintf(SDOG_NOTICE, "sheepdog daemon (version %s) started\n", PACKAGE_VERSION);
 
 	while (!sys_stat_shutdown() || sys->nr_outstanding_reqs != 0)
diff --git a/sheep/trace/graph.c b/sheep/trace/graph.c
index 94a4f71..fff9060 100644
--- a/sheep/trace/graph.c
+++ b/sheep/trace/graph.c
@@ -68,6 +68,8 @@ notrace unsigned long trace_return_call(void)
 
 notrace void trace_init_buffer(struct list_head *list)
 {
+	int sz = sizeof(struct trace_graph_item);
+	rbuffer_create(&rbuf, TRACE_BUF_LEN / sz, sz);
 	list_add(&rbuf.list, list);
 }
 
diff --git a/sheep/trace/trace.c b/sheep/trace/trace.c
index 225b715..be0d94c 100644
--- a/sheep/trace/trace.c
+++ b/sheep/trace/trace.c
@@ -19,7 +19,9 @@ static pthread_mutex_t trace_lock = PTHREAD_MUTEX_INITIALIZER;
 
 static trace_func_t trace_func = trace_call;
 static int trace_count;
+static int trace_buffer_inited;
 
+static LIST_HEAD(buffer_list);
 pthread_cond_t trace_cond = PTHREAD_COND_INITIALIZER;
 pthread_mutex_t trace_mux = PTHREAD_MUTEX_INITIALIZER;
 
@@ -37,6 +39,8 @@ static notrace void suspend(int num)
 
 	pthread_mutex_lock(&trace_mux);
 	trace_count--;
+	if (!trace_buffer_inited)
+		trace_init_buffer(&buffer_list); /* init worker threads rbuffer */
 	pthread_cond_wait(&trace_cond, &trace_mux);
 	pthread_mutex_unlock(&trace_mux);
 	dprintf("worker thread going to resume\n");
@@ -176,6 +180,7 @@ wait_for_worker_suspend:
 		goto wait_for_worker_suspend;
 	}
 	pthread_mutex_unlock(&trace_mux);
+	trace_buffer_inited = 1;
 }
 
 static notrace void resume_worker_threads(void)
@@ -246,6 +251,30 @@ int init_signal(void)
 	return 0;
 }
 
+notrace int trace_copy_buffer(void *buf)
+{
+	struct rbuffer *rbuf;
+	int total = 0;
+
+	list_for_each_entry(rbuf, &buffer_list, list) {
+		int rbuf_size = rbuffer_size(rbuf);
+		if (rbuf_size) {
+			memcpy((char *)buf + total, rbuf->buffer, rbuf_size);
+			total += rbuf_size;
+		}
+	}
+	return total;
+}
+
+notrace void trace_reset_buffer(void)
+{
+	struct rbuffer *rbuf;
+
+	list_for_each_entry(rbuf, &buffer_list, list) {
+		rbuffer_reset(rbuf);
+	}
+}
+
 notrace int trace_init()
 {
 	sigset_t block;
@@ -262,6 +291,7 @@ notrace int trace_init()
 		return -1;
 	}
 
+	trace_init_buffer(&buffer_list); /* init main thread ring buffer */
 	replace_mcount_call((unsigned long)do_trace_init);
 	dprintf("main thread %u\n", (int)pthread_self());
 	dprintf("trace support enabled.\n");
diff --git a/sheep/trace/trace.h b/sheep/trace/trace.h
index 38ecd1b..3baefab 100644
--- a/sheep/trace/trace.h
+++ b/sheep/trace/trace.h
@@ -49,14 +49,26 @@ extern void trace_return_caller(void);
 extern unsigned long trace_return_call(void);
 
 /* trace.c */
-extern pthread_cond_t trace_cond;
-extern pthread_mutex_t trace_mux;
+#ifdef ENABLE_TRACE
+  extern pthread_cond_t trace_cond;
+  extern pthread_mutex_t trace_mux;
 
-extern int trace_init(void);
-extern int register_trace_function(trace_func_t func);
-extern int trace_enable(void);
-extern int trace_disable(void);
-extern struct caller *trace_lookup_ip(unsigned long ip, int create);
+  extern int init_signal(void);
+  extern int trace_init(void);
+  extern int register_trace_function(trace_func_t func);
+  extern int trace_enable(void);
+  extern int trace_disable(void);
+  extern struct caller *trace_lookup_ip(unsigned long ip, int create);
+  extern int trace_copy_buffer(void *buf);
+  extern void trace_reset_buffer(void);
+#else
+  static inline int init_signal(void) {return 0;}
+  static inline int trace_init(void) {return 0;}
+  static inline int trace_enable(void) {return 0;}
+  static inline int trace_disable(void) {return 0;}
+  static inline int trace_copy_buffer(void *buf) {return 0;}
+  static inline void trace_reset_buffer(void) {}
+#endif /* ENABLE_TRACE */
 
 #define register_tracer(new)			\
 static void __attribute__((constructor))	\
-- 
1.7.8.2




More information about the sheepdog mailing list