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 |