sim: profile: implement --profile-file backend

The profile code already has options and handling for accepting a file to
write the profile output like the trace code, but it doesn't actually use
it.  At the moment, it simply opens the file at the start and closes it at
the end.  So add two new local functions the way the trace code is doing
it and have them figure out whether to write the output to stdout or the
specified file.  Then convert all existing output in the profile code to
use these helpers.

Signed-off-by: Mike Frysinger <vapier@gentoo.org>

3 files changed, 150 insertions, 111 deletions

diff --git a/sim/common/ChangeLog b/sim/common/ChangeLog
index 9e0f6dd..ae25963 100644
--- a/sim/common/ChangeLog
+++ b/sim/common/ChangeLog
@@ -1,3 +1,17 @@
+2010-04-21  Mike Frysinger  <vapier@gentoo.org>
+
+	* sim-profile.c (profile_vprintf, profile_printf): New functions.
+	(profile_print_pc): Convert sim_io_printf to profile_printf.
+	(profile_print_insn): Likewise.
+	(profile_print_memory): Likewise.
+	(profile_print_core): Likewise.
+	(profile_print_model): Likewise.
+	(sim_profile_print_bar): Likewise.
+	(profile_print_speed): Likewise.
+	(profile_print_addr_ranges): Likewise.
+	(profile_info): Likewise.
+	* sim-profile.h (sim_profile_print_bar): Add cpu argument.
+
 2010-04-19  Mike Frysinger  <vapier@gentoo.org>
 
 	* sim-model.c (OPTION_MODEL): Convert to enum.
diff --git a/sim/common/sim-profile.c b/sim/common/sim-profile.c
index 5f6b3f1..e7bcd3e 100644
--- a/sim/common/sim-profile.c
+++ b/sim/common/sim-profile.c
@@ -452,6 +452,31 @@ profile_option_handler (SIM_DESC sd,
   return SIM_RC_OK;
 }
 
+/* Profiling output hooks.  */
+
+static void
+profile_vprintf (SIM_DESC sd, sim_cpu *cpu, const char *fmt, va_list ap)
+{
+  FILE *fp = PROFILE_FILE (CPU_PROFILE_DATA (cpu));
+
+  /* If an output file was given, redirect output to that.  */
+  if (fp != NULL)
+    vfprintf (fp, fmt, ap);
+  else
+    sim_io_evprintf (sd, fmt, ap);
+}
+
+__attribute__ ((format (printf, 3, 4)))
+static void
+profile_printf (SIM_DESC sd, sim_cpu *cpu, const char *fmt, ...)
+{
+  va_list ap;
+
+  va_start (ap, fmt);
+  profile_vprintf (sd, cpu, fmt, ap);
+  va_end (ap);
+}
+
 /* PC profiling support */
 
 #if WITH_PROFILE_PC_P
@@ -600,7 +625,7 @@ profile_print_pc (sim_cpu *cpu, int verbose)
   if (PROFILE_PC_COUNT (profile) == 0)
     return;
 
-  sim_io_printf (sd, "Program Counter Statistics:\n\n");
+  profile_printf (sd, cpu, "Program Counter Statistics:\n\n");
 
   /* First pass over data computes various things.  */
   max_val = 0;
@@ -612,45 +637,45 @@ profile_print_pc (sim_cpu *cpu, int verbose)
 	max_val = PROFILE_PC_COUNT (profile) [i];
     }
 
-  sim_io_printf (sd, "  Total samples: %s\n",
-		 COMMAS (total));
-  sim_io_printf (sd, "  Granularity: %s bytes per bucket\n",
-		 COMMAS (PROFILE_PC_BUCKET_SIZE (profile)));
-  sim_io_printf (sd, "  Size: %s buckets\n",
-		 COMMAS (PROFILE_PC_NR_BUCKETS (profile)));
-  sim_io_printf (sd, "  Frequency: %s cycles per sample\n",
-		 COMMAS (PROFILE_PC_FREQ (profile)));
+  profile_printf (sd, cpu, "  Total samples: %s\n",
+		  COMMAS (total));
+  profile_printf (sd, cpu, "  Granularity: %s bytes per bucket\n",
+		  COMMAS (PROFILE_PC_BUCKET_SIZE (profile)));
+  profile_printf (sd, cpu, "  Size: %s buckets\n",
+		  COMMAS (PROFILE_PC_NR_BUCKETS (profile)));
+  profile_printf (sd, cpu, "  Frequency: %s cycles per sample\n",
+		  COMMAS (PROFILE_PC_FREQ (profile)));
 
   if (PROFILE_PC_END (profile) != 0)
-    sim_io_printf (sd, "  Range: 0x%lx 0x%lx\n",
-		   (long) PROFILE_PC_START (profile),
+    profile_printf (sd, cpu, "  Range: 0x%lx 0x%lx\n",
+		    (long) PROFILE_PC_START (profile),
 		   (long) PROFILE_PC_END (profile));
 
   if (verbose && max_val != 0)
     {
       /* Now we can print the histogram.  */
-      sim_io_printf (sd, "\n");
+      profile_printf (sd, cpu, "\n");
       for (i = 0; i <= PROFILE_PC_NR_BUCKETS (profile); ++i)
 	{
 	  if (PROFILE_PC_COUNT (profile) [i] != 0)
 	    {
-	      sim_io_printf (sd, "  ");
+	      profile_printf (sd, cpu, "  ");
 	      if (i == PROFILE_PC_NR_BUCKETS (profile))
-		sim_io_printf (sd, "%10s:", "overflow");
+		profile_printf (sd, cpu, "%10s:", "overflow");
 	      else
-		sim_io_printf (sd, "0x%08lx:",
-			       (long) (PROFILE_PC_START (profile)
-				       + (i * PROFILE_PC_BUCKET_SIZE (profile))));
-	      sim_io_printf (sd, " %*s",
-			     max_val < 10000 ? 5 : 10,
-			     COMMAS (PROFILE_PC_COUNT (profile) [i]));
-	      sim_io_printf (sd, " %4.1f",
-			     (PROFILE_PC_COUNT (profile) [i] * 100.0) / total);
-	      sim_io_printf (sd, ": ");
-	      sim_profile_print_bar (sd, PROFILE_HISTOGRAM_WIDTH,
+		profile_printf (sd, cpu, "0x%08lx:",
+				(long) (PROFILE_PC_START (profile)
+					+ (i * PROFILE_PC_BUCKET_SIZE (profile))));
+	      profile_printf (sd, cpu, " %*s",
+			      max_val < 10000 ? 5 : 10,
+			      COMMAS (PROFILE_PC_COUNT (profile) [i]));
+	      profile_printf (sd, cpu, " %4.1f",
+			      (PROFILE_PC_COUNT (profile) [i] * 100.0) / total);
+	      profile_printf (sd, cpu, ": ");
+	      sim_profile_print_bar (sd, cpu, PROFILE_HISTOGRAM_WIDTH,
 				     PROFILE_PC_COUNT (profile) [i],
 				     max_val);
-	      sim_io_printf (sd, "\n");
+	      profile_printf (sd, cpu, "\n");
 	    }
 	}
     }
@@ -709,7 +734,7 @@ profile_print_pc (sim_cpu *cpu, int verbose)
       }
   }
 
-  sim_io_printf (sd, "\n");
+  profile_printf (sd, cpu, "\n");
 }
 
 #endif
@@ -746,12 +771,12 @@ profile_print_insn (sim_cpu *cpu, int verbose)
   if (CPU_MAX_INSNS (cpu) == 0)
     return;
 
-  sim_io_printf (sd, "Instruction Statistics");
+  profile_printf (sd, cpu, "Instruction Statistics");
 #ifdef SIM_HAVE_ADDR_RANGE
   if (PROFILE_RANGE (data)->ranges)
-    sim_io_printf (sd, " (for selected address range(s))");
+    profile_printf (sd, cpu, " (for selected address range(s))");
 #endif
-  sim_io_printf (sd, "\n\n");
+  profile_printf (sd, cpu, "\n\n");
 
   /* First pass over data computes various things.  */
   max_val = 0;
@@ -774,12 +799,12 @@ profile_print_insn (sim_cpu *cpu, int verbose)
   if (! PROFILE_TOTAL_INSN_COUNT (data))
     PROFILE_TOTAL_INSN_COUNT (data) = total;
 
-  sim_io_printf (sd, "  Total: %s insns\n", COMMAS (total));
+  profile_printf (sd, cpu, "  Total: %s insns\n", COMMAS (total));
 
   if (verbose && max_val != 0)
     {
       /* Now we can print the histogram.  */
-      sim_io_printf (sd, "\n");
+      profile_printf (sd, cpu, "\n");
       for (i = 0; i < CPU_MAX_INSNS (cpu); ++i)
 	{
 	  const char *name = (*CPU_INSN_NAME (cpu)) (cpu, i);
@@ -788,19 +813,19 @@ profile_print_insn (sim_cpu *cpu, int verbose)
 	    continue;
 	  if (PROFILE_INSN_COUNT (data) [i] != 0)
 	    {
-	      sim_io_printf (sd, "   %*s: %*s: ",
-			     max_name_len, name,
-			     max_val < 10000 ? 5 : 10,
-			     COMMAS (PROFILE_INSN_COUNT (data) [i]));
-	      sim_profile_print_bar (sd, PROFILE_HISTOGRAM_WIDTH,
+	      profile_printf (sd, cpu, "   %*s: %*s: ",
+			      max_name_len, name,
+			      max_val < 10000 ? 5 : 10,
+			      COMMAS (PROFILE_INSN_COUNT (data) [i]));
+	      sim_profile_print_bar (sd, cpu, PROFILE_HISTOGRAM_WIDTH,
 				     PROFILE_INSN_COUNT (data) [i],
 				     max_val);
-	      sim_io_printf (sd, "\n");
+	      profile_printf (sd, cpu, "\n");
 	    }
 	}
     }
 
-  sim_io_printf (sd, "\n");
+  profile_printf (sd, cpu, "\n");
 }
 
 #endif
@@ -818,7 +843,7 @@ profile_print_memory (sim_cpu *cpu, int verbose)
   PROFILE_DATA *data = CPU_PROFILE_DATA (cpu);
   char comma_buf[20];
 
-  sim_io_printf (sd, "Memory Access Statistics\n\n");
+  profile_printf (sd, cpu, "Memory Access Statistics\n\n");
 
   /* First pass over data computes various things.  */
   max_val = total_read = total_write = max_name_len = 0;
@@ -836,45 +861,45 @@ profile_print_memory (sim_cpu *cpu, int verbose)
     }
 
   /* One could use PROFILE_LABEL_WIDTH here.  I chose not to.  */
-  sim_io_printf (sd, "  Total read:  %s accesses\n",
-		 COMMAS (total_read));
-  sim_io_printf (sd, "  Total write: %s accesses\n",
-		 COMMAS (total_write));
+  profile_printf (sd, cpu, "  Total read:  %s accesses\n",
+		  COMMAS (total_read));
+  profile_printf (sd, cpu, "  Total write: %s accesses\n",
+		  COMMAS (total_write));
 
   if (verbose && max_val != 0)
     {
       /* FIXME: Need to separate instruction fetches from data fetches
 	 as the former swamps the latter.  */
       /* Now we can print the histogram.  */
-      sim_io_printf (sd, "\n");
+      profile_printf (sd, cpu, "\n");
       for (i = 0; i < MODE_TARGET_MAX; ++i)
 	{
 	  if (PROFILE_READ_COUNT (data) [i] != 0)
 	    {
-	      sim_io_printf (sd, "   %*s read:  %*s: ",
-			     max_name_len, MODE_NAME (i),
-			     max_val < 10000 ? 5 : 10,
-			     COMMAS (PROFILE_READ_COUNT (data) [i]));
-	      sim_profile_print_bar (sd, PROFILE_HISTOGRAM_WIDTH,
+	      profile_printf (sd, cpu, "   %*s read:  %*s: ",
+			      max_name_len, MODE_NAME (i),
+			      max_val < 10000 ? 5 : 10,
+			      COMMAS (PROFILE_READ_COUNT (data) [i]));
+	      sim_profile_print_bar (sd, cpu, PROFILE_HISTOGRAM_WIDTH,
 				     PROFILE_READ_COUNT (data) [i],
 				     max_val);
-	      sim_io_printf (sd, "\n");
+	      profile_printf (sd, cpu, "\n");
 	    }
 	  if (PROFILE_WRITE_COUNT (data) [i] != 0)
 	    {
-	      sim_io_printf (sd, "   %*s write: %*s: ",
-			     max_name_len, MODE_NAME (i),
-			     max_val < 10000 ? 5 : 10,
-			     COMMAS (PROFILE_WRITE_COUNT (data) [i]));
-	      sim_profile_print_bar (sd, PROFILE_HISTOGRAM_WIDTH,
+	      profile_printf (sd, cpu, "   %*s write: %*s: ",
+			      max_name_len, MODE_NAME (i),
+			      max_val < 10000 ? 5 : 10,
+			      COMMAS (PROFILE_WRITE_COUNT (data) [i]));
+	      sim_profile_print_bar (sd, cpu, PROFILE_HISTOGRAM_WIDTH,
 				     PROFILE_WRITE_COUNT (data) [i],
 				     max_val);
-	      sim_io_printf (sd, "\n");
+	      profile_printf (sd, cpu, "\n");
 	    }
 	}
     }
 
-  sim_io_printf (sd, "\n");
+  profile_printf (sd, cpu, "\n");
 }
 
 #endif
@@ -891,7 +916,7 @@ profile_print_core (sim_cpu *cpu, int verbose)
   PROFILE_DATA *data = CPU_PROFILE_DATA (cpu);
   char comma_buf[20];
 
-  sim_io_printf (sd, "CORE Statistics\n\n");
+  profile_printf (sd, cpu, "CORE Statistics\n\n");
 
   /* First pass over data computes various things.  */
   {
@@ -907,31 +932,31 @@ profile_print_core (sim_cpu *cpu, int verbose)
   }
 
   /* One could use PROFILE_LABEL_WIDTH here.  I chose not to.  */
-  sim_io_printf (sd, "  Total:  %s accesses\n",
-		 COMMAS (total));
+  profile_printf (sd, cpu, "  Total:  %s accesses\n",
+		  COMMAS (total));
 
   if (verbose && max_val != 0)
     {
       unsigned map;
       /* Now we can print the histogram.  */
-      sim_io_printf (sd, "\n");
+      profile_printf (sd, cpu, "\n");
       for (map = 0; map < nr_maps; map++)
 	{
 	  if (PROFILE_CORE_COUNT (data) [map] != 0)
 	    {
-	      sim_io_printf (sd, "%10s:", map_to_str (map));
-	      sim_io_printf (sd, "%*s: ",
-			     max_val < 10000 ? 5 : 10,
-			     COMMAS (PROFILE_CORE_COUNT (data) [map]));
-	      sim_profile_print_bar (sd, PROFILE_HISTOGRAM_WIDTH,
+	      profile_printf (sd, cpu, "%10s:", map_to_str (map));
+	      profile_printf (sd, cpu, "%*s: ",
+			      max_val < 10000 ? 5 : 10,
+			      COMMAS (PROFILE_CORE_COUNT (data) [map]));
+	      sim_profile_print_bar (sd, cpu, PROFILE_HISTOGRAM_WIDTH,
 				     PROFILE_CORE_COUNT (data) [map],
 				     max_val);
-	      sim_io_printf (sd, "\n");
+	      profile_printf (sd, cpu, "\n");
 	    }
 	}
     }
 
-  sim_io_printf (sd, "\n");
+  profile_printf (sd, cpu, "\n");
 }
 
 #endif
@@ -948,35 +973,35 @@ profile_print_model (sim_cpu *cpu, int verbose)
   unsigned long total_cycles = PROFILE_MODEL_TOTAL_CYCLES (data);
   char comma_buf[20];
 
-  sim_io_printf (sd, "Model %s Timing Information",
-		 MODEL_NAME (CPU_MODEL (cpu)));
+  profile_printf (sd, cpu, "Model %s Timing Information",
+		  MODEL_NAME (CPU_MODEL (cpu)));
 #ifdef SIM_HAVE_ADDR_RANGE
   if (PROFILE_RANGE (data)->ranges)
-    sim_io_printf (sd, " (for selected address range(s))");
+    profile_printf (sd, cpu, " (for selected address range(s))");
 #endif
-  sim_io_printf (sd, "\n\n");
-  sim_io_printf (sd, "  %-*s %s\n",
-		 PROFILE_LABEL_WIDTH, "Taken branches:",
-		 COMMAS (PROFILE_MODEL_TAKEN_COUNT (data)));
-  sim_io_printf (sd, "  %-*s %s\n",
-		 PROFILE_LABEL_WIDTH, "Untaken branches:",
-		 COMMAS (PROFILE_MODEL_UNTAKEN_COUNT (data)));
-  sim_io_printf (sd, "  %-*s %s\n",
-		 PROFILE_LABEL_WIDTH, "Cycles stalled due to branches:",
-		 COMMAS (cti_stall_cycles));
-  sim_io_printf (sd, "  %-*s %s\n",
-		 PROFILE_LABEL_WIDTH, "Cycles stalled due to loads:",
-		 COMMAS (load_stall_cycles));
-  sim_io_printf (sd, "  %-*s %s\n",
-		 PROFILE_LABEL_WIDTH, "Total cycles (*approximate*):",
-		 COMMAS (total_cycles));
-  sim_io_printf (sd, "\n");
+  profile_printf (sd, cpu, "\n\n");
+  profile_printf (sd, cpu, "  %-*s %s\n",
+		  PROFILE_LABEL_WIDTH, "Taken branches:",
+		  COMMAS (PROFILE_MODEL_TAKEN_COUNT (data)));
+  profile_printf (sd, cpu, "  %-*s %s\n",
+		  PROFILE_LABEL_WIDTH, "Untaken branches:",
+		  COMMAS (PROFILE_MODEL_UNTAKEN_COUNT (data)));
+  profile_printf (sd, cpu, "  %-*s %s\n",
+		  PROFILE_LABEL_WIDTH, "Cycles stalled due to branches:",
+		  COMMAS (cti_stall_cycles));
+  profile_printf (sd, cpu, "  %-*s %s\n",
+		  PROFILE_LABEL_WIDTH, "Cycles stalled due to loads:",
+		  COMMAS (load_stall_cycles));
+  profile_printf (sd, cpu, "  %-*s %s\n",
+		  PROFILE_LABEL_WIDTH, "Total cycles (*approximate*):",
+		  COMMAS (total_cycles));
+  profile_printf (sd, cpu, "\n");
 }
 
 #endif
 
 void
-sim_profile_print_bar (SIM_DESC sd, unsigned int width,
+sim_profile_print_bar (SIM_DESC sd, sim_cpu *cpu, unsigned int width,
 		       unsigned int val, unsigned int max_val)
 {
   unsigned int i, count;
@@ -984,7 +1009,7 @@ sim_profile_print_bar (SIM_DESC sd, unsigned int width,
   count = ((double) val / (double) max_val) * (double) width;
 
   for (i = 0; i < count; ++i)
-    sim_io_printf (sd, "*");
+    profile_printf (sd, cpu, "*");
 }
 
 /* Print the simulator's execution speed for CPU.  */
@@ -1000,13 +1025,13 @@ profile_print_speed (sim_cpu *cpu)
   double secs;
   char comma_buf[20];
 
-  sim_io_printf (sd, "Simulator Execution Speed\n\n");
+  profile_printf (sd, cpu, "Simulator Execution Speed\n\n");
 
   if (total != 0)
-    sim_io_printf (sd, "  Total instructions:      %s\n", COMMAS (total));
+    profile_printf (sd, cpu, "  Total instructions:      %s\n", COMMAS (total));
 
   if (milliseconds < 1000)
-    sim_io_printf (sd, "  Total execution time:    < 1 second\n\n");
+    profile_printf (sd, cpu, "  Total execution time:    < 1 second\n\n");
   else
     {
       /* The printing of the time rounded to 2 decimal places makes the speed
@@ -1015,13 +1040,13 @@ profile_print_speed (sim_cpu *cpu)
 	 better that the user not perceive there's a math error.  */
       secs = (double) milliseconds / 1000;
       secs = ((double) (unsigned long) (secs * 100 + .5)) / 100;
-      sim_io_printf (sd, "  Total execution time   : %.2f seconds\n", secs);
+      profile_printf (sd, cpu, "  Total execution time   : %.2f seconds\n", secs);
       /* Don't confuse things with data that isn't useful.
 	 If we ran for less than 2 seconds, only use the data if we
 	 executed more than 100,000 insns.  */
       if (secs >= 2 || total >= 100000)
-	sim_io_printf (sd, "  Simulator speed:         %s insns/second\n",
-		       COMMAS ((unsigned long) ((double) total / secs)));
+	profile_printf (sd, cpu, "  Simulator speed:         %s insns/second\n",
+			COMMAS ((unsigned long) ((double) total / secs)));
     }
 
   /* Print simulated execution time if the cpu frequency has been specified.  */
@@ -1029,10 +1054,10 @@ profile_print_speed (sim_cpu *cpu)
   if (clock != 0)
     {
       if (clock >= 1000000)
-	sim_io_printf (sd, "  Simulated cpu frequency: %.2f MHz\n",
-		       clock / 1000000);
+	profile_printf (sd, cpu, "  Simulated cpu frequency: %.2f MHz\n",
+			clock / 1000000);
       else
-	sim_io_printf (sd, "  Simulated cpu frequency: %.2f Hz\n", clock);
+	profile_printf (sd, cpu, "  Simulated cpu frequency: %.2f Hz\n", clock);
 
 #if WITH_PROFILE_MODEL_P
       if (PROFILE_FLAGS (data) [PROFILE_MODEL_IDX])
@@ -1044,8 +1069,8 @@ profile_print_speed (sim_cpu *cpu)
 	     error.  */
 	  secs = PROFILE_MODEL_TOTAL_CYCLES (data) / clock;
 	  secs = ((double) (unsigned long) (secs * 100 + .5)) / 100;
-	  sim_io_printf (sd, "  Simulated execution time: %.2f seconds\n",
-			 secs);
+	  profile_printf (sd, cpu, "  Simulated execution time: %.2f seconds\n",
+			  secs);
 	}
 #endif /* WITH_PROFILE_MODEL_P */
     }
@@ -1062,14 +1087,14 @@ profile_print_addr_ranges (sim_cpu *cpu)
 
   if (asr)
     {
-      sim_io_printf (sd, "Selected address ranges\n\n");
+      profile_printf (sd, cpu, "Selected address ranges\n\n");
       while (asr != NULL)
 	{
-	  sim_io_printf (sd, "  0x%lx - 0x%lx\n",
-			 (long) asr->start, (long) asr->end);
+	  profile_printf (sd, cpu, "  0x%lx - 0x%lx\n",
+			  (long) asr->start, (long) asr->end);
 	  asr = asr->next;
 	}
-      sim_io_printf (sd, "\n");
+      profile_printf (sd, cpu, "\n");
     }
 }
 #endif
@@ -1104,11 +1129,11 @@ profile_info (SIM_DESC sd, int verbose)
 
       for (i = 0; i < MAX_PROFILE_VALUES; ++i)
 	if (PROFILE_FLAGS (data) [i])
-	  print_title_p = 1;
-      /* One could break out early if print_title_p is set.  */
+	  {
+	    profile_printf (sd, cpu, "Summary profiling results:\n\n");
+	    print_title_p = 1;
+	  }
     }
-  if (print_title_p)
-    sim_io_printf (sd, "Summary profiling results:\n\n");
 
   /* Loop, cpu by cpu, printing results.  */
 
@@ -1139,7 +1164,7 @@ profile_info (SIM_DESC sd, int verbose)
 #endif
 	      ))
 	{
-	  sim_io_printf (sd, "CPU %d\n\n", c);
+	  profile_printf (sd, cpu, "CPU %d\n\n", c);
 	}
 
 #ifdef SIM_HAVE_ADDR_RANGE
diff --git a/sim/common/sim-profile.h b/sim/common/sim-profile.h
index c35fe0c..04aea52 100644
--- a/sim/common/sim-profile.h
+++ b/sim/common/sim-profile.h
@@ -308,6 +308,6 @@ do { \
 
 /* Misc. utilities.  */
 
-extern void sim_profile_print_bar (SIM_DESC, unsigned int, unsigned int, unsigned int);
+extern void sim_profile_print_bar (SIM_DESC, SIM_CPU *, unsigned int, unsigned int, unsigned int);
 
 #endif /* SIM_PROFILE_H */