trace-cmd record: Change the status output during runs

The output status is quite confusing. Seeing a blob like this:

CPU: 0
entries: 12
overrun: 0
commit overrun: 0
bytes: 3612
oldest event ts: 49097.376154
now ts: 49097.647663
dropped events: 0
read events: 147

Is pretty much useless for most people, and even confuses some (I get
confused by it sometimes).

Instead, cut it down to something much easier to read. We really only
care about overruns and commit overruns, but only if there are any.

Have it output like his instead:

CPU 2: 165358 bytes lost

Where it only shows us the CPUs that lost events.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

2 files changed, 80 insertions, 32 deletions

diff --git a/trace-local.h b/trace-local.h
index 7e0a25f1..c08e728b 100644
--- a/trace-local.h
+++ b/trace-local.h
@@ -155,7 +155,8 @@ struct buffer_instance {
 
 	const char		*clock;
 
-	struct trace_seq	*s;
+	struct trace_seq	*s_save;
+	struct trace_seq	*s_print;
 
 	struct tracecmd_input	*handle;
 
diff --git a/trace-record.c b/trace-record.c
index 1eb4fdf8..a6cf33bb 100644
--- a/trace-record.c
+++ b/trace-record.c
@@ -2565,8 +2565,8 @@ add_buffer_stat(struct tracecmd_output *handle, struct buffer_instance *instance
 
 	for (i = 0; i < cpu_count; i++)
 		tracecmd_add_option(handle, TRACECMD_OPTION_CPUSTAT,
-				    instance->s[i].len+1,
-				    instance->s[i].buffer);
+				    instance->s_save[i].len+1,
+				    instance->s_save[i].buffer);
 }
 
 static void add_option_hooks(struct tracecmd_output *handle)
@@ -2613,6 +2613,17 @@ static void touch_file(const char *file)
 	close(fd);
 }
 
+static void print_stat(struct buffer_instance *instance)
+{
+	int cpu;
+
+	if (!is_top_instance(instance))
+		printf("\nBuffer: %s\n\n", instance->name);
+
+	for (cpu = 0; cpu < cpu_count; cpu++)
+		trace_seq_do_printf(&instance->s_print[cpu]);
+}
+
 static void record_data(char *date2ts)
 {
 	struct tracecmd_option **buffer_options;
@@ -2656,7 +2667,7 @@ static void record_data(char *date2ts)
 
 		/* Only record the top instance under TRACECMD_OPTION_CPUSTAT*/
 		if (!no_top_instance()) {
-			struct trace_seq *s = top_instance.s;
+			struct trace_seq *s = top_instance.s_save;
 
 			for (i = 0; i < cpu_count; i++)
 				tracecmd_add_option(handle, TRACECMD_OPTION_CPUSTAT,
@@ -2679,6 +2690,9 @@ static void record_data(char *date2ts)
 			}
 		}
 
+		if (!no_top_instance())
+			print_stat(&top_instance);
+
 		tracecmd_append_cpu_data(handle, cpu_count, temp_files);
 
 		for (i = 0; i < cpu_count; i++)
@@ -2687,6 +2701,7 @@ static void record_data(char *date2ts)
 		if (buffers) {
 			i = 0;
 			for_each_instance(instance) {
+				print_stat(instance);
 				append_buffer(handle, buffer_options[i++], instance, temp_files);
 			}
 		}
@@ -3383,22 +3398,67 @@ static void allocate_seq(void)
 {
 	struct buffer_instance *instance;
 
-	for_all_instances(instance)
-		instance->s = malloc_or_die(sizeof(struct trace_seq) * cpu_count);
+	for_all_instances(instance) {
+		instance->s_save = malloc_or_die(sizeof(struct trace_seq) * cpu_count);
+		instance->s_print = malloc_or_die(sizeof(struct trace_seq) * cpu_count);
+	}
+}
+
+/* Find the overrun output, and add it to the print seq */
+static void add_overrun(int cpu, struct trace_seq *src, struct trace_seq *dst)
+{
+	const char overrun_str[] = "overrun: ";
+	const char commit_overrun_str[] = "commit overrun: ";
+	const char *p;
+	int overrun;
+	int commit_overrun;
+
+	p = strstr(src->buffer, overrun_str);
+	if (!p) {
+		/* Warn? */
+		trace_seq_printf(dst, "CPU %d: no overrun found?\n", cpu);
+		return;
+	}
+
+	overrun = atoi(p + sizeof(overrun_str));
+
+	p = strstr(p + 9, commit_overrun_str);
+	if (p)
+		commit_overrun = atoi(p + sizeof(commit_overrun_str));
+	else
+		commit_overrun = -1;
+
+	if (!overrun && !commit_overrun)
+		return;
+
+	trace_seq_printf(dst, "CPU %d:", cpu);
+
+	if (overrun)
+		trace_seq_printf(dst, " %d bytes lost", overrun);
+
+	if (commit_overrun)
+		trace_seq_printf(dst, " %d bytes lost due to commit overrun",
+				 commit_overrun);
+
+	trace_seq_putc(dst, '\n');
 }
 
 static void record_stats(void)
 {
 	struct buffer_instance *instance;
-	struct trace_seq *s;
+	struct trace_seq *s_save;
+	struct trace_seq *s_print;
 	int cpu;
 
 	for_all_instances(instance) {
-		s = instance->s;
+		s_save = instance->s_save;
+		s_print = instance->s_print;
 		for (cpu = 0; cpu < cpu_count; cpu++) {
-			trace_seq_init(&s[cpu]);
-			trace_seq_printf(&s[cpu], "CPU: %d\n", cpu);
-			tracecmd_stat_cpu_instance(instance, &s[cpu], cpu);
+			trace_seq_init(&s_save[cpu]);
+			trace_seq_init(&s_print[cpu]);
+			trace_seq_printf(&s_save[cpu], "CPU: %d\n", cpu);
+			tracecmd_stat_cpu_instance(instance, &s_save[cpu], cpu);
+			add_overrun(cpu, &s_save[cpu], &s_print[cpu]);
 		}
 	}
 }
@@ -3406,19 +3466,9 @@ static void record_stats(void)
 static void print_stats(void)
 {
 	struct buffer_instance *instance;
-	int cpu;
 
-	for_all_instances(instance) {
-		if (!is_top_instance(instance)) {
-			if (instance != first_instance)
-				printf("\n");
-			printf("Buffer: %s\n\n", instance->name);
-		}
-		for (cpu = 0; cpu < cpu_count; cpu++) {
-			trace_seq_do_printf(&instance->s[cpu]);
-			printf("\n");
-		}
-	}
+	for_all_instances(instance)
+		print_stat(instance);
 }
 
 static void destroy_stats(void)
@@ -3427,8 +3477,10 @@ static void destroy_stats(void)
 	int cpu;
 
 	for_all_instances(instance) {
-		for (cpu = 0; cpu < cpu_count; cpu++)
-			trace_seq_destroy(&instance->s[cpu]);
+		for (cpu = 0; cpu < cpu_count; cpu++) {
+			trace_seq_destroy(&instance->s_save[cpu]);
+			trace_seq_destroy(&instance->s_print[cpu]);
+		}
 	}
 }
 
@@ -4192,12 +4244,6 @@ void trace_record (int argc, char **argv)
 	if (!keep)
 		disable_all(0);
 
-	printf("Kernel buffer statistics:\n"
-	       "  Note: \"entries\" are the entries left in the kernel ring buffer and are not\n"
-	       "        recorded in the trace data. They should all be zero.\n\n");
-
-	print_stats();
-
 	/* extract records the date after extraction */
 	if (extract && date) {
 		/*
@@ -4211,7 +4257,8 @@ void trace_record (int argc, char **argv)
 	if (record || extract) {
 		record_data(date2ts);
 		delete_thread_data();
-	}
+	} else
+		print_stats();
 
 	destroy_stats();