From: Liu Yuan <[email protected]> usage: after tracing the sheep, you can get a function graph: collie debug trace -C or 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 <[email protected]> --- collie/collie.c | 1 + collie/debug.c | 79 +++++++++++++++++++++++++++++++++++++++++++++++++- include/sheep.h | 1 + sheep/ops.c | 14 +++++++++ sheep/trace/graph.c | 2 + sheep/trace/trace.c | 30 +++++++++++++++++++ sheep/trace/trace.h | 2 + 7 files changed, 127 insertions(+), 2 deletions(-) diff --git a/collie/collie.c b/collie/collie.c index 6215349..dda979f 100644 --- a/collie/collie.c +++ b/collie/collie.c @@ -51,6 +51,7 @@ static const struct sd_option collie_options[] = { /* debug options */ {'e', "begin", 0, "begin tracing"}, {'t', "stop", 0, "stop tracing"}, + {'C', "cat", 0, "cat trace output"}, { 0, NULL, 0, NULL }, }; diff --git a/collie/debug.c b/collie/debug.c index 2fbda2d..cf5bd29 100644 --- a/collie/debug.c +++ b/collie/debug.c @@ -2,21 +2,93 @@ struct debug_cmd_data { int t_enable; + int t_cat; } debug_cmd_data; -static int debug_trace(int argc, char **argv) +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; + struct sd_req hdr; + struct sd_rsp *rsp = (struct sd_rsp *)&hdr; + unsigned rlen, wlen; + + if (debug_cmd_data.t_cat) + return do_trace_cat(); + + fd = connect_to(sdhost, sdport); + if (fd < 0) + return EXIT_SYSFAIL; + + memset(&hdr, 0, sizeof(hdr)); hdr.opcode = SD_OP_TRACE; hdr.epoch = node_list_version; hdr.data_length = debug_cmd_data.t_enable; @@ -49,13 +121,16 @@ static int debug_parser(int ch, char *opt) case 't': debug_cmd_data.t_enable = 0; break; + case 'C': + debug_cmd_data.t_cat = 1; + break; } return 0; } static struct subcommand debug_cmd[] = { - {"trace", NULL, "etaprh", "debug the cluster", + {"trace", NULL, "etCaprh", "debug the cluster", 0, debug_trace}, {NULL,}, }; diff --git a/include/sheep.h b/include/sheep.h index be74f22..958b117 100644 --- a/include/sheep.h +++ b/include/sheep.h @@ -43,6 +43,7 @@ #define SD_OP_RESTORE 0x92 #define SD_OP_GET_SNAP_FILE 0x93 #define SD_OP_TRACE 0x94 +#define SD_OP_TRACE_CAT 0x95 #define SD_FLAG_CMD_IO_LOCAL 0x0010 #define SD_FLAG_CMD_RECOVERY 0x0020 diff --git a/sheep/ops.c b/sheep/ops.c index b41962c..4c9a8f4 100644 --- a/sheep/ops.c +++ b/sheep/ops.c @@ -467,6 +467,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 */ @@ -587,6 +595,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/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 463d667..ac2eddd 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 @@ 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"); @@ -175,6 +179,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) @@ -231,6 +236,30 @@ notrace int trace_disable(void) return SD_RES_SUCCESS; } +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; @@ -247,6 +276,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..1e6185f 100644 --- a/sheep/trace/trace.h +++ b/sheep/trace/trace.h @@ -57,6 +57,8 @@ 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); #define register_tracer(new) \ static void __attribute__((constructor)) \ -- 1.7.8.2 -- sheepdog mailing list [email protected] http://lists.wpkg.org/mailman/listinfo/sheepdog
