diff options
author | Chris Mason <chris.mason@fusionio.com> | 2012-08-16 14:46:33 -0400 |
---|---|---|
committer | Chris Mason <chris.mason@fusionio.com> | 2012-08-16 14:46:33 -0400 |
commit | e199d5465c01b67bd6a1ce15eb7b96ad46e51bbf (patch) | |
tree | cb7ae2d229f5856373154927985a72e754f97edf | |
parent | 9e066e233bbe8cff186975681d35023f9e6f1b02 (diff) | |
download | blktrace-e199d5465c01b67bd6a1ce15eb7b96ad46e51bbf.tar.gz |
iowatcher: Add mpstat graphing support
Signed-off-by: Chris Mason <chris.mason@fusionio.com>
-rw-r--r-- | iowatcher/Makefile | 2 | ||||
-rw-r--r-- | iowatcher/blkparse.c | 3 | ||||
-rw-r--r-- | iowatcher/blkparse.h | 7 | ||||
-rw-r--r-- | iowatcher/main.c | 223 | ||||
-rw-r--r-- | iowatcher/plot.c | 18 | ||||
-rw-r--r-- | iowatcher/plot.h | 1 | ||||
-rw-r--r-- | iowatcher/tracers.c | 85 | ||||
-rw-r--r-- | iowatcher/tracers.h | 4 |
8 files changed, 311 insertions, 32 deletions
diff --git a/iowatcher/Makefile b/iowatcher/Makefile index f15e5b2..0e96043 100644 --- a/iowatcher/Makefile +++ b/iowatcher/Makefile @@ -18,7 +18,7 @@ all: $(ALL) %.o: %.c $(CC) -o $*.o -c $(ALL_CFLAGS) $< -iowatcher: blkparse.o plot.o main.o tracers.o +iowatcher: blkparse.o plot.o main.o tracers.o mpstat.o $(CC) $(ALL_CFLAGS) -o $@ $(filter %.o,$^) -lm depend: diff --git a/iowatcher/blkparse.c b/iowatcher/blkparse.c index a587d54..d254811 100644 --- a/iowatcher/blkparse.c +++ b/iowatcher/blkparse.c @@ -424,7 +424,7 @@ static char *find_trace_file(char *filename) return strdup(filename); snprintf(line, 1024, "%s.%s", filename, "dump"); - ret = stat(filename, &st); + ret = stat(line, &st); if (ret == 0) return strdup(line); @@ -468,7 +468,6 @@ struct trace *open_trace(char *filename) fprintf(stderr, "Unable to find trace file %s\n", filename); goto fail; } - free(filename); filename = found_filename; fd = open(filename, O_RDONLY); diff --git a/iowatcher/blkparse.h b/iowatcher/blkparse.h index 3f32430..ff14191 100644 --- a/iowatcher/blkparse.h +++ b/iowatcher/blkparse.h @@ -41,6 +41,13 @@ struct trace { int found_issue; int found_completion; int found_queue; + + char *mpstat_start; + char *mpstat_cur; + u64 mpstat_len; + int mpstat_fd; + int mpstat_seconds; + int mpstat_num_cpus; }; static inline unsigned int MAJOR(unsigned int dev) diff --git a/iowatcher/main.c b/iowatcher/main.c index ded1afe..ebc41cb 100644 --- a/iowatcher/main.c +++ b/iowatcher/main.c @@ -36,9 +36,12 @@ #include "blkparse.h" #include "list.h" #include "tracers.h" +#include "mpstat.h" LIST_HEAD(all_traces); +static int found_mpstat = 0; +static int cpu_color_index = 0; static int color_index = 0; char *colors[] = { "blue", "darkgreen", @@ -61,27 +64,46 @@ char *pick_color(void) { } char *pick_cpu_color(void) { - char *ret = colors[color_index]; + char *ret = colors[cpu_color_index]; if (!ret) { color_index = 0; - ret = colors[color_index]; + ret = colors[cpu_color_index]; } - color_index++; + cpu_color_index++; return ret; } enum { IO_GRAPH_INDEX = 0, TPUT_GRAPH_INDEX, + CPU_SYS_GRAPH_INDEX, + CPU_IO_GRAPH_INDEX, + CPU_IRQ_GRAPH_INDEX, + CPU_SOFT_GRAPH_INDEX, + CPU_USER_GRAPH_INDEX, LATENCY_GRAPH_INDEX, QUEUE_DEPTH_GRAPH_INDEX, IOPS_GRAPH_INDEX, TOTAL_GRAPHS }; +enum { + MPSTAT_SYS = 0, + MPSTAT_IRQ, + MPSTAT_IO, + MPSTAT_SOFT, + MPSTAT_USER, + MPSTAT_GRAPHS +}; + static char *graphs_by_name[] = { "io", "tput", + "cpu-sys", + "cpu-io", + "cpu-irq", + "cpu-soft", + "cpu-user", "latency", "queue-depth", "iops", @@ -112,8 +134,28 @@ struct trace_file { struct graph_line_data *queue_depth_gld; struct graph_dot_data *gdd_writes; struct graph_dot_data *gdd_reads; + + int mpstat_seconds; + int mpstat_stop_seconds; + struct graph_line_data **mpstat_gld; }; +static void alloc_mpstat_gld(struct trace_file *tf) +{ + struct graph_line_data **ptr; + + if (tf->trace->mpstat_num_cpus == 0) + return; + + ptr = calloc((tf->trace->mpstat_num_cpus + 1) * MPSTAT_GRAPHS, + sizeof(struct graph_line_data *)); + if (!ptr) { + perror("Unable to allocate mpstat arrays\n"); + exit(1); + } + tf->mpstat_gld = ptr; +} + static void enable_all_graphs(void) { int i; @@ -162,7 +204,6 @@ static int last_graph(void) } return -ENOENT; } - static void add_trace_file(char *filename) { struct trace_file *tf; @@ -172,6 +213,7 @@ static void add_trace_file(char *filename) fprintf(stderr, "Unable to allocate memory\n"); exit(1); } + tf->label = ""; tf->filename = strdup(filename); list_add_tail(&tf->list, &all_traces); tf->read_color = pick_color(); @@ -182,6 +224,7 @@ static void add_trace_file(char *filename) static void setup_trace_file_graphs(void) { struct trace_file *tf; + int i; list_for_each_entry(tf, &all_traces, list) { tf->tput_gld = alloc_line_data(tf->seconds, tf->stop_seconds); @@ -190,6 +233,17 @@ static void setup_trace_file_graphs(void) tf->iop_gld = alloc_line_data(tf->seconds, tf->stop_seconds); tf->gdd_writes = alloc_dot_data(tf->seconds, tf->max_offset, tf->stop_seconds); tf->gdd_reads = alloc_dot_data(tf->seconds, tf->max_offset, tf->stop_seconds); + + if (tf->trace->mpstat_num_cpus == 0) + continue; + + alloc_mpstat_gld(tf); + for (i = 0; i < (tf->trace->mpstat_num_cpus + 1) * MPSTAT_GRAPHS; i++) { + tf->mpstat_gld[i] = + alloc_line_data(tf->mpstat_seconds, + tf->mpstat_seconds); + tf->mpstat_gld[i]->max = 100; + } } } @@ -214,6 +268,12 @@ static void read_traces(void) filter_outliers(trace, tf->max_offset, &ymin, &ymax); tf->max_offset = ymax; + + read_mpstat(trace, tf->filename); + tf->mpstat_stop_seconds = trace->mpstat_seconds; + tf->mpstat_seconds = trace->mpstat_seconds; + if (tf->mpstat_seconds) + found_mpstat = 1; } } @@ -223,6 +283,11 @@ static void read_trace_events(void) struct trace_file *tf; struct trace *trace; int ret; + int i; + int time; + double user, sys, iowait, irq, soft; + double max_user = 0, max_sys = 0, max_iowait = 0, + max_irq = 0, max_soft = 0; list_for_each_entry(tf, &all_traces, list) { trace = tf->trace; @@ -239,6 +304,57 @@ static void read_trace_events(void) break; } } + list_for_each_entry(tf, &all_traces, list) { + trace = tf->trace; + + if (trace->mpstat_num_cpus == 0) + continue; + + first_mpstat(trace); + + for (time = 0; time < tf->mpstat_stop_seconds; time ++) { + for (i = 0; i < (trace->mpstat_num_cpus + 1) * MPSTAT_GRAPHS; i += MPSTAT_GRAPHS) { + ret = read_mpstat_event(trace, &user, &sys, + &iowait, &irq, &soft); + if (ret) + goto mpstat_done; + if (next_mpstat_line(trace)) + goto mpstat_done; + + if (sys > max_sys) + max_sys = sys; + if (user > max_user) + max_user = user; + if (irq > max_irq) + max_irq = irq; + if (iowait > max_iowait) + max_iowait = iowait; + + add_mpstat_gld(time, sys, tf->mpstat_gld[i + MPSTAT_SYS]); + add_mpstat_gld(time, irq, tf->mpstat_gld[i + MPSTAT_IRQ]); + add_mpstat_gld(time, soft, tf->mpstat_gld[i + MPSTAT_SOFT]); + add_mpstat_gld(time, user, tf->mpstat_gld[i + MPSTAT_USER]); + add_mpstat_gld(time, iowait, tf->mpstat_gld[i + MPSTAT_IO]); + } + if (next_mpstat(trace) == NULL) + break; + } + } + +mpstat_done: + list_for_each_entry(tf, &all_traces, list) { + trace = tf->trace; + + if (trace->mpstat_num_cpus == 0) + continue; + + tf->mpstat_gld[MPSTAT_SYS]->max = max_sys; + tf->mpstat_gld[MPSTAT_IRQ]->max = max_irq; + tf->mpstat_gld[MPSTAT_SOFT]->max = max_soft; + tf->mpstat_gld[MPSTAT_USER]->max = max_user; + tf->mpstat_gld[MPSTAT_IO]->max = max_iowait;; + } + return; } static void set_trace_label(char *label) @@ -471,6 +587,91 @@ static void plot_tput(struct plot *plot, int seconds) close_plot(plot); } +static void plot_cpu(struct plot *plot, int seconds, char *label, + int active_index, int gld_index) +{ + struct trace_file *tf; + char line[128]; + int max = 0; + int i; + int gld_i; + char *color; + double avg = 0; + int ymax; + int plotted = 0; + + if (active_graphs[active_index] == 0) + return; + + list_for_each_entry(tf, &all_traces, list) { + if (tf->trace->mpstat_num_cpus > max) + max = tf->trace->mpstat_num_cpus; + } + if (max == 0) + return; + + tf = list_entry(all_traces.next, struct trace_file, list); + + ymax = tf->mpstat_gld[gld_index]->max; + if (ymax == 0) + return; + + svg_alloc_legend(plot, num_traces * max); + + plot->add_xlabel = last_active_graph == active_index; + setup_axis(plot); + set_plot_label(plot, label); + + seconds = tf->mpstat_seconds; + + set_yticks(plot, 4, 0, tf->mpstat_gld[gld_index]->max, ""); + set_ylabel(plot, "Percent"); + set_xticks(plot, 9, 0, seconds); + + cpu_color_index = 0; + list_for_each_entry(tf, &all_traces, list) { + for (i = 0; i < tf->mpstat_gld[0]->stop_seconds; i++) { + avg += tf->mpstat_gld[gld_index]->data[i].sum; + } + avg /= tf->mpstat_gld[gld_index]->stop_seconds; + color = pick_cpu_color(); + svg_line_graph(plot, tf->mpstat_gld[0], color); + svg_add_legend(plot, tf->label, " avg", color); + + for (i = 1; i < tf->trace->mpstat_num_cpus + 1; i++) { + struct graph_line_data *gld = tf->mpstat_gld[i * MPSTAT_GRAPHS + gld_index]; + double this_avg = 0; + + for (gld_i = 0; gld_i < gld->stop_seconds; gld_i++) + this_avg += gld->data[i].sum; + + this_avg /= gld->stop_seconds; + + for (gld_i = 0; gld_i < gld->stop_seconds; gld_i++) { + if (this_avg > avg + 30 || + gld->data[gld_i].sum > 95) { + color = pick_cpu_color(); + svg_line_graph(plot, gld, color); + snprintf(line, 128, " CPU %d\n", i - 1); + svg_add_legend(plot, tf->label, line, color); + plotted++; + break; + } + + } + } + } + + if (plot->add_xlabel) + set_xlabel(plot, "Time (seconds)"); + + if (plot->legend_index <= 8) + svg_write_legend(plot); + else + svg_free_legend(plot); + close_plot(plot); +} + static void plot_latency(struct plot *plot, int seconds) { struct trace_file *tf; @@ -622,6 +823,7 @@ int main(int ac, char **av) fprintf(stderr, "exiting due to blktrace failure\n"); exit(1); } + start_mpstat(blktrace_outfile); if (program_to_run) { ret = run_program(program_to_run); if (ret) { @@ -665,7 +867,7 @@ int main(int ac, char **av) write_svg_header(fd); plot = alloc_plot(fd); - if (active_graphs[IO_GRAPH_INDEX]) + if (active_graphs[IO_GRAPH_INDEX] || found_mpstat) set_legend_width(longest_label + strlen("writes")); else if (num_traces > 1) set_legend_width(longest_label); @@ -676,6 +878,17 @@ int main(int ac, char **av) plot_io(plot, seconds, max_offset); plot_tput(plot, seconds); + plot_cpu(plot, seconds, "CPU IO Wait Time", + CPU_IO_GRAPH_INDEX, MPSTAT_IO); + plot_cpu(plot, seconds, "CPU System Time", + CPU_SYS_GRAPH_INDEX, MPSTAT_SYS); + plot_cpu(plot, seconds, "CPU IRQ Time", + CPU_IRQ_GRAPH_INDEX, MPSTAT_IRQ); + plot_cpu(plot, seconds, "CPU SoftIRQ Time", + CPU_SOFT_GRAPH_INDEX, MPSTAT_SOFT); + plot_cpu(plot, seconds, "CPU User Time", + CPU_USER_GRAPH_INDEX, MPSTAT_USER); + plot_latency(plot, seconds); plot_queue_depth(plot, seconds); plot_iops(plot, seconds); diff --git a/iowatcher/plot.c b/iowatcher/plot.c index 785d230..da64d41 100644 --- a/iowatcher/plot.c +++ b/iowatcher/plot.c @@ -58,11 +58,11 @@ int legend_y_off = -10; int legend_font_size = 15; int legend_width = 80; +static int rolling_avg_secs = 0; + static int line_len = 1024; static char line[1024]; -static int rolling_avg_secs = 0; - struct graph_line_data *alloc_line_data(int seconds, int stop_seconds) { int size = sizeof(struct graph_line_data) + (stop_seconds + 1) * sizeof(struct graph_line_pair); @@ -647,11 +647,21 @@ void svg_alloc_legend(struct plot *plot, int num_lines) plot->num_legend_lines = num_lines; } -void svg_write_legend(struct plot *plot) +void svg_free_legend(struct plot *plot) { int i; + for (i = 0; i < plot->legend_index; i++) + free(plot->legend_lines[i]); + free(plot->legend_lines); + plot->legend_lines = NULL; + plot->legend_index = 0; +} + +void svg_write_legend(struct plot *plot) +{ int legend_line_x = axis_x_off(graph_width) + legend_x_off; int legend_line_y = axis_y_off(graph_height) + legend_y_off; + int i; if (plot->legend_index == 0) return; @@ -670,8 +680,8 @@ void svg_write_legend(struct plot *plot) free(plot->legend_lines[i]); } free(plot->legend_lines); + plot->legend_lines = NULL; plot->legend_index = 0; - plot->legend_lines = 0; } void svg_add_legend(struct plot *plot, char *text, char *extra, char *color) diff --git a/iowatcher/plot.h b/iowatcher/plot.h index 655dac0..cf52447 100644 --- a/iowatcher/plot.h +++ b/iowatcher/plot.h @@ -112,4 +112,5 @@ void svg_add_legend(struct plot *plot, char *text, char *extra, char *color); void svg_alloc_legend(struct plot *plot, int num_lines); void set_legend_width(int longest_str); void set_rolling_avg(int rolling); +void svg_free_legend(struct plot *plot); #endif diff --git a/iowatcher/tracers.c b/iowatcher/tracers.c index 3309bef..acced94 100644 --- a/iowatcher/tracers.c +++ b/iowatcher/tracers.c @@ -36,9 +36,14 @@ #include "blkparse.h" #include "list.h" +static int line_len = 1024; +static char line[1024]; + static pid_t blktrace_pid = 0; +static pid_t mpstat_pid = 0; char *blktrace_args[] = { + "blktrace", "-d", NULL, "-b", "16384", "-o", "trace", @@ -49,26 +54,31 @@ char *blktrace_args[] = { NULL, }; -#define DEVICE_INDEX 1 -#define DEST_DIR_INDEX 7 -#define TRACE_NAME_INDEX 5 +char *mpstat_args[] = { + "mpstat", + "-P", "ALL", "1", + NULL, +}; + +#define DEVICE_INDEX 2 +#define DEST_DIR_INDEX 8 +#define TRACE_NAME_INDEX 6 -int stop_blktrace(void) +int stop_tracer(pid_t *tracer_pid) { int ret; - pid_t pid; + pid_t pid = *tracer_pid; pid_t pid_ret; int status = 0; - if (blktrace_pid == 0) + if (pid == 0) return 0; - pid = blktrace_pid; - blktrace_pid = 0; + *tracer_pid = 0; ret = kill(pid, SIGTERM); if (ret) { - fprintf(stderr, "failed to stop blktrace pid %lu error %s\n", - (unsigned long)blktrace_pid, strerror(errno)); + fprintf(stderr, "failed to stop tracer pid %lu error %s\n", + (unsigned long)pid, strerror(errno)); return -errno; } pid_ret = waitpid(pid, &status, WUNTRACED); @@ -81,7 +91,8 @@ int stop_blktrace(void) void stop_all_tracers(void) { - stop_blktrace(); + stop_tracer(&blktrace_pid); + stop_tracer(&mpstat_pid); } void sig_handler_for_quit(int val) @@ -138,27 +149,63 @@ int run_program(char *str) stop_all_tracers(); return -errno; } - stop_blktrace(); + stop_all_tracers(); return 0; } int wait_for_tracers(void) { int status = 0; - if (blktrace_pid == 0) - return 0; - - waitpid(blktrace_pid, &status, WUNTRACED); - blktrace_pid = 0; + if (blktrace_pid != 0) { + waitpid(blktrace_pid, &status, WUNTRACED); + blktrace_pid = 0; + } + if (mpstat_pid != 0) { + waitpid(mpstat_pid, &status, WUNTRACED); + mpstat_pid = 0; + } return 0; } int blktrace_to_dump(char *trace_name) { - char line[1024]; - snprintf(line, 1024, "blkparse -O -i %s -d '%s.%s'", + snprintf(line, line_len, "blkparse -O -i %s -d '%s.%s'", trace_name, trace_name, "dump"); system(line); return 0; } + +int start_mpstat(char *trace_name) +{ + int fd; + pid_t pid; + + snprintf(line, line_len, "%s.mpstat", trace_name); + + fd = open(line, O_WRONLY | O_CREAT | O_TRUNC); + if (fd < 0) { + fprintf(stderr, "unable to open %s for writing err %s\n", + line, strerror(errno)); + exit(1); + } + pid = fork(); + if (pid == 0) { + int ret; + + close(1); + ret = dup2(fd, 1); + if (ret < 0) { + fprintf(stderr, "failed to setup output file for mpstat\n"); + exit(1); + } + ret = execvp("mpstat", mpstat_args); + if (ret < 0) { + fprintf(stderr, "failed to exec mpstat err %s\n", + strerror(ret)); + exit(1); + } + } + mpstat_pid = pid; + return 0; +} diff --git a/iowatcher/tracers.h b/iowatcher/tracers.h index f9b71d6..7ceeefe 100644 --- a/iowatcher/tracers.h +++ b/iowatcher/tracers.h @@ -20,8 +20,10 @@ int run_program(char *str); int stop_blktrace(void); int start_blktrace(char *device, char *trace_name, char *dest); -void stop_all_tracers(int val); +int start_mpstat(char *trace_name); int wait_for_tracers(void); int blktrace_to_dump(char *trace_name); +int start_mpstat(char *trace_name); + #endif |