Add mpstat graphing support

Signed-off-by: Chris Mason <chris.mason@fusionio.com>

8 files changed, 311 insertions, 32 deletions

diff --git a/Makefile b/Makefile
index f15e5b2..0e96043 100644
--- a/Makefile
+++ b/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/blkparse.c b/blkparse.c
index a587d54..d254811 100644
--- a/blkparse.c
+++ b/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/blkparse.h b/blkparse.h
index 3f32430..ff14191 100644
--- a/blkparse.h
+++ b/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/main.c b/main.c
index ded1afe..ebc41cb 100644
--- a/main.c
+++ b/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/plot.c b/plot.c
index 785d230..da64d41 100644
--- a/plot.c
+++ b/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/plot.h b/plot.h
index 655dac0..cf52447 100644
--- a/plot.h
+++ b/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/tracers.c b/tracers.c
index 3309bef..acced94 100644
--- a/tracers.c
+++ b/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/tracers.h b/tracers.h
index f9b71d6..7ceeefe 100644
--- a/tracers.h
+++ b/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