Time profiler introduced.

Co-Authored-By: Jan Hubicka <jh@suse.cz>

From-SVN: r204690

gcc/ChangeLog

+2013-11-11  Martin Liska  <marxin.liska@gmail.com>
+						Jan Hubicka  <jh@suse.cz>
+
+	* cgraph.c (dump_cgraph_node): Profile dump added.
+	* cgraph.h (struct cgraph_node): New time profile variable added.
+	* cgraphclones.c (cgraph_clone_node): Time profile is cloned.
+	* gcov-io.h (gcov_type): New profiler type introduced.
+	* ipa-profile.c (lto_output_node): Streaming for time profile added.
+	(input_node): Time profiler is read from LTO stream.
+	* predict.c (maybe_hot_count_p): Hot prediction changed.
+	* profile.c (instrument_values): New case for time profiler added.
+	(compute_value_histograms): Read of time profile.
+	* tree-pretty-print.c (dump_function_header): Time profiler is dumped.
+	* tree-profile.c (init_ic_make_global_vars): Time profiler function added.
+	(gimple_init_edge_profiler): TP function instrumentation.
+	(gimple_gen_time_profiler): New.
+	* value-prof.c (gimple_add_histogram_value): Support for time profiler
+	added.
+	(dump_histogram_value): TP type added to dumps.
+	(visit_hist): More sensitive check that takes TP into account.
+	(gimple_find_values_to_profile): TP instrumentation.
+	* value-prof.h (hist_type): New histogram type added.
+	(struct histogram_value_t): Pointer to struct function added.
+	* libgcc/Makefile.in: New GCOV merge function for TP added.
+	* libgcov.c: function_counter variable introduced.
+	(_gcov_merge_time_profile): New.
+	(_gcov_time_profiler): New.
+
 2013-11-11  Marc Glisse  <marc.glisse@inria.fr>
 	    Jeff Law  <law@redhat.com>
 

gcc/cgraph.c

@@ -1890,6 +1890,7 @@ dump_cgraph_node (FILE *f, struct cgraph_node *node)
   if (node->profile_id)
     fprintf (f, "  Profile id: %i\n",
 	     node->profile_id);
+  fprintf (f, "  First run: %i\n", node->tp_first_run);
   fprintf (f, "  Function flags:");
   if (node->count)
     fprintf (f, " executed "HOST_WIDEST_INT_PRINT_DEC"x",

gcc/cgraph.h

@@ -298,6 +298,8 @@ public:
   int uid;
   /* ID assigned by the profiling.  */
   unsigned int profile_id;
+  /* Time profiler: first run of function.  */
+  int tp_first_run;
 
   /* Set when decl is an abstract function pointed to by the
      ABSTRACT_DECL_ORIGIN of a reachable function.  */

gcc/cgraphclones.c

@@ -208,6 +208,7 @@ cgraph_clone_node (struct cgraph_node *n, tree decl, gcov_type count, int freq,
   new_node->frequency = n->frequency;
   new_node->clone = n->clone;
   new_node->clone.tree_map = NULL;
+  new_node->tp_first_run = n->tp_first_run;
   if (n->count)
     {
       if (new_node->count > n->count)

gcc/gcov-io.h

@@ -342,9 +342,10 @@ typedef unsigned HOST_WIDEST_INT gcov_type_unsigned;
 				      counter.  */
 #define GCOV_COUNTER_IOR	7  /* IOR of the all values passed to
 				      counter.  */
-#define GCOV_LAST_VALUE_COUNTER 7  /* The last of counters used for value
+#define GCOV_TIME_PROFILER  8 /* Time profile collecting first run of a function */
+#define GCOV_LAST_VALUE_COUNTER 8  /* The last of counters used for value
 				      profiling.  */
-#define GCOV_COUNTERS		8
+#define GCOV_COUNTERS		9
 
 /* Number of counters used for value profiling.  */
 #define GCOV_N_VALUE_COUNTERS \
@@ -352,7 +353,7 @@ typedef unsigned HOST_WIDEST_INT gcov_type_unsigned;
 
   /* A list of human readable names of the counters */
 #define GCOV_COUNTER_NAMES	{"arcs", "interval", "pow2", "single", \
-      				 "delta", "indirect_call", "average", "ior"}
+              "delta", "indirect_call", "average", "ior", "time_profiler"}
 
   /* Names of merge functions for counters.  */
 #define GCOV_MERGE_FUNCTIONS	{"__gcov_merge_add",	\
@@ -362,7 +363,8 @@ typedef unsigned HOST_WIDEST_INT gcov_type_unsigned;
 				 "__gcov_merge_delta",  \
 				 "__gcov_merge_single", \
 				 "__gcov_merge_add",	\
-				 "__gcov_merge_ior"}
+				 "__gcov_merge_ior",  \
+         "__gcov_merge_time_profile" }
 
 /* Convert a counter index to a tag.  */
 #define GCOV_TAG_FOR_COUNTER(COUNT)				\
@@ -511,6 +513,8 @@ extern void __gcov_merge_delta (gcov_type *, unsigned) ATTRIBUTE_HIDDEN;
 /* The merge function that just ors the counters together.  */
 extern void __gcov_merge_ior (gcov_type *, unsigned) ATTRIBUTE_HIDDEN;
 
+extern void __gcov_merge_time_profile (gcov_type *, unsigned) ATTRIBUTE_HIDDEN;
+
 /* The profiler functions.  */
 extern void __gcov_interval_profiler (gcov_type *, gcov_type, int, unsigned);
 extern void __gcov_pow2_profiler (gcov_type *, gcov_type);
@@ -518,6 +522,7 @@ extern void __gcov_one_value_profiler (gcov_type *, gcov_type);
 extern void __gcov_indirect_call_profiler_v2 (gcov_type, void *);
 extern void __gcov_average_profiler (gcov_type *, gcov_type);
 extern void __gcov_ior_profiler (gcov_type *, gcov_type);
+extern void __gcov_time_profiler (gcov_type *);
 
 #ifndef inhibit_libc
 /* The wrappers around some library functions..  */

gcc/lto-cgraph.c

@@ -482,6 +482,8 @@ lto_output_node (struct lto_simple_output_block *ob, struct cgraph_node *node,
     ref = LCC_NOT_FOUND;
   streamer_write_hwi_stream (ob->main_stream, ref);
 
+  streamer_write_hwi_stream (ob->main_stream, node->tp_first_run);
+
   bp = bitpack_create (ob->main_stream);
   bp_pack_value (&bp, node->local.local, 1);
   bp_pack_value (&bp, node->externally_visible, 1);
@@ -1077,7 +1079,10 @@ input_node (struct lto_file_decl_data *file_data,
     internal_error ("bytecode stream: found multiple instances of cgraph "
 		    "node with uid %d", node->uid);
 
+  node->tp_first_run = streamer_read_uhwi (ib);
+
   bp = streamer_read_bitpack (ib);
+
   input_overwrite_node (file_data, node, tag, &bp);
 
   /* Store a reference for now, and fix up later to be a pointer.  */

gcc/lto/lto-symtab.c

@@ -29,6 +29,7 @@ along with GCC; see the file COPYING3.  If not see
 #include "plugin-api.h"
 #include "lto-streamer.h"
 #include "ipa-utils.h"
+#include "ipa-inline.h"
 
 /* Replace the cgraph node NODE with PREVAILING_NODE in the cgraph, merging
    all edges and removing the old node.  */
@@ -84,6 +85,12 @@ lto_cgraph_replace_node (struct cgraph_node *node,
   if (node->decl != prevailing_node->decl)
     cgraph_release_function_body (node);
 
+  /* Time profile merging */
+  if (node->tp_first_run)
+    prevailing_node->tp_first_run = prevailing_node->tp_first_run ?
+      MIN (prevailing_node->tp_first_run, node->tp_first_run) :
+      node->tp_first_run;
+
   /* Finally remove the replaced node.  */
   cgraph_remove_node (node);
 }

gcc/profile.c

@@ -65,6 +65,7 @@ along with GCC; see the file COPYING3.  If not see
 #include "tree-cfg.h"
 #include "cfgloop.h"
 #include "dumpfile.h"
+#include "cgraph.h"
 
 #include "profile.h"
 
@@ -188,6 +189,15 @@ instrument_values (histogram_values values)
 	  gimple_gen_ior_profiler (hist, t, 0);
 	  break;
 
+  case HIST_TYPE_TIME_PROFILE:
+    {
+      basic_block bb = split_edge (single_succ_edge (ENTRY_BLOCK_PTR));
+      gimple_stmt_iterator gsi = gsi_start_bb (bb);
+
+      gimple_gen_time_profiler (t, 0, gsi);
+      break;
+    }
+
 	default:
 	  gcc_unreachable ();
 	}
@@ -850,6 +860,7 @@ compute_value_histograms (histogram_values values, unsigned cfg_checksum,
   gcov_type *histogram_counts[GCOV_N_VALUE_COUNTERS];
   gcov_type *act_count[GCOV_N_VALUE_COUNTERS];
   gcov_type *aact_count;
+  struct cgraph_node *node;
 
   for (t = 0; t < GCOV_N_VALUE_COUNTERS; t++)
     n_histogram_counters[t] = 0;
@@ -888,6 +899,7 @@ compute_value_histograms (histogram_values values, unsigned cfg_checksum,
       t = (int) hist->type;
 
       aact_count = act_count[t];
+
       if (act_count[t])
         act_count[t] += hist->n_counters;
 
@@ -895,9 +907,22 @@ compute_value_histograms (histogram_values values, unsigned cfg_checksum,
       hist->hvalue.counters =  XNEWVEC (gcov_type, hist->n_counters);
       for (j = 0; j < hist->n_counters; j++)
         if (aact_count)
-	  hist->hvalue.counters[j] = aact_count[j];
-	else
-	  hist->hvalue.counters[j] = 0;
+          hist->hvalue.counters[j] = aact_count[j];
+        else
+          hist->hvalue.counters[j] = 0;
+
+      /* Time profiler counter is not related to any statement,
+         so that we have to read the counter and set the value to
+         the corresponding call graph node.  */
+      if (hist->type == HIST_TYPE_TIME_PROFILE)
+        {
+          node = cgraph_get_node (hist->fun->decl);
+
+          node->tp_first_run = hist->hvalue.counters[0];
+
+          if (dump_file)
+            fprintf (dump_file, "Read tp_first_run: %d\n", node->tp_first_run);
+        }
     }
 
   for (t = 0; t < GCOV_N_VALUE_COUNTERS; t++)

gcc/testsuite/ChangeLog

+2013-11-11  Martin Liska	<marxin.liska@gmail.com>
+
+	* gcc.dg/time-profiler-1.c: New test.
+	* gcc.dg/time-profiler-2.c: Ditto.
+
 2013-11-11  Marc Glisse  <marc.glisse@inria.fr>
 	    Jeff Law  <law@redhat.com>
 

gcc/testsuite/gcc.dg/tree-prof/time-profiler-1.c

+/* { dg-options "-O2 -fdump-ipa-profile" } */
+
+__attribute__ ((noinline))
+int foo()
+{
+  return 0;
+}
+
+__attribute__ ((noinline))
+int bar()
+{
+  return 1;
+}
+
+int main ()
+{
+  return foo ();
+}
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 0" 1 "profile"} } */
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 1" 1 "profile"} } */
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 2" 1 "profile"} } */
+/* { dg-final-use { cleanup-ipa-dump "profile" } } */

gcc/testsuite/gcc.dg/tree-prof/time-profiler-2.c

+/* { dg-options "-O2 -fdump-ipa-profile" } */
+
+#include <unistd.h>
+
+__attribute__ ((noinline))
+int foo()
+{
+  return 1;
+}
+
+__attribute__ ((noinline))
+int bar()
+{
+  return 1;
+}
+
+__attribute__ ((noinline))
+int baz()
+{
+  return 1;
+}
+
+__attribute__ ((noinline))
+int baz1()
+{
+  return 1;
+}
+
+int main ()
+{
+  int f = fork();
+  int r = 0;
+
+  foo ();
+
+  if (f < 0)
+    return 1; /* Fork failed.  */
+
+  if(f == 0) /* Child process.  */
+    r = bar() - foo();
+  else /* Parent process.  */
+    r = foo() - foo();
+
+  return r;
+}
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 0" 2 "profile"} } */
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 1" 1 "profile"} } */
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 2" 1 "profile"} } */
+/* { dg-final-use { scan-ipa-dump-times "Read tp_first_run: 3" 1 "profile"} } */
+/* { dg-final-use { cleanup-ipa-dump "profile" } } */

gcc/tree-profile.c

@@ -51,9 +51,10 @@ static GTY(()) tree tree_interval_profiler_fn;
 static GTY(()) tree tree_pow2_profiler_fn;
 static GTY(()) tree tree_one_value_profiler_fn;
 static GTY(()) tree tree_indirect_call_profiler_fn;
+static GTY(()) tree tree_time_profiler_fn;
 static GTY(()) tree tree_average_profiler_fn;
 static GTY(()) tree tree_ior_profiler_fn;
-
+
 
 static GTY(()) tree ic_void_ptr_var;
 static GTY(()) tree ic_gcov_type_ptr_var;
@@ -63,7 +64,8 @@ static GTY(()) tree ptr_void;
 
 /* Add code:
    __thread gcov*	__gcov_indirect_call_counters; // pointer to actual counter
-   __thread  void*	__gcov_indirect_call_callee; // actual callee address
+   __thread void*	__gcov_indirect_call_callee; // actual callee address
+   __thread int __gcov_function_counter; // time profiler function counter
 */
 static void
 init_ic_make_global_vars (void)
@@ -145,6 +147,7 @@ gimple_init_edge_profiler (void)
   tree gcov_type_ptr;
   tree ic_profiler_fn_type;
   tree average_profiler_fn_type;
+  tree time_profiler_fn_type;
 
   if (!gcov_type_node)
     {
@@ -222,6 +225,18 @@ gimple_init_edge_profiler (void)
 	= tree_cons (get_identifier ("leaf"), NULL,
 		     DECL_ATTRIBUTES (tree_indirect_call_profiler_fn));
 
+      /* void (*) (gcov_type *, gcov_type, void *)  */
+      time_profiler_fn_type
+	       = build_function_type_list (void_type_node,
+					  gcov_type_ptr, NULL_TREE);
+      tree_time_profiler_fn
+	      = build_fn_decl ("__gcov_time_profiler",
+				     time_profiler_fn_type);
+      TREE_NOTHROW (tree_time_profiler_fn) = 1;
+      DECL_ATTRIBUTES (tree_time_profiler_fn)
+	= tree_cons (get_identifier ("leaf"), NULL,
+		     DECL_ATTRIBUTES (tree_time_profiler_fn));
+
       /* void (*) (gcov_type *, gcov_type)  */
       average_profiler_fn_type
 	      = build_function_type_list (void_type_node,
@@ -247,6 +262,7 @@ gimple_init_edge_profiler (void)
       DECL_ASSEMBLER_NAME (tree_pow2_profiler_fn);
       DECL_ASSEMBLER_NAME (tree_one_value_profiler_fn);
       DECL_ASSEMBLER_NAME (tree_indirect_call_profiler_fn);
+      DECL_ASSEMBLER_NAME (tree_time_profiler_fn);
       DECL_ASSEMBLER_NAME (tree_average_profiler_fn);
       DECL_ASSEMBLER_NAME (tree_ior_profiler_fn);
     }
@@ -455,6 +471,23 @@ gimple_gen_ic_func_profiler (void)
   gsi_insert_before (&gsi, stmt2, GSI_SAME_STMT);
 }
 
+/* Output instructions as GIMPLE tree at the beginning for each function.
+   TAG is the tag of the section for counters, BASE is offset of the
+   counter position and GSI is the iterator we place the counter.  */
+
+void
+gimple_gen_time_profiler (unsigned tag, unsigned base,
+                          gimple_stmt_iterator &gsi)
+{
+  tree ref_ptr = tree_coverage_counter_addr (tag, base);
+  gimple call;
+
+  ref_ptr = force_gimple_operand_gsi (&gsi, ref_ptr,
+				      true, NULL_TREE, true, GSI_SAME_STMT);
+  call = gimple_build_call (tree_time_profiler_fn, 1, ref_ptr);
+  gsi_insert_before (&gsi, call, GSI_NEW_STMT);
+}
+
 /* Output instructions as GIMPLE trees for code to find the most common value
    of a difference between two evaluations of an expression.
    VALUE is the expression whose value is profiled.  TAG is the tag of the

gcc/value-prof.c

@@ -196,6 +196,7 @@ gimple_add_histogram_value (struct function *fun, gimple stmt,
 {
   hist->hvalue.next = gimple_histogram_value (fun, stmt);
   set_histogram_value (fun, stmt, hist);
+  hist->fun = fun;
 }
 
 
@@ -338,6 +339,15 @@ dump_histogram_value (FILE *dump_file, histogram_value hist)
 	}
       fprintf (dump_file, ".\n");
       break;
+    case HIST_TYPE_TIME_PROFILE:
+      fprintf (dump_file, "Time profile ");
+      if (hist->hvalue.counters)
+      {
+        fprintf (dump_file, "time:"HOST_WIDEST_INT_PRINT_DEC,
+                 (HOST_WIDEST_INT) hist->hvalue.counters[0]);
+      }
+      fprintf (dump_file, ".\n");
+      break;
     case HIST_TYPE_MAX:
       gcc_unreachable ();
    }
@@ -411,6 +421,7 @@ stream_in_histogram_value (struct lto_input_block *ib, gimple stmt)
 	  break;
 
 	case HIST_TYPE_IOR:
+  case HIST_TYPE_TIME_PROFILE:
 	  ncounters = 1;
 	  break;
 	case HIST_TYPE_MAX:
@@ -496,7 +507,9 @@ visit_hist (void **slot, void *data)
 {
   struct pointer_set_t *visited = (struct pointer_set_t *) data;
   histogram_value hist = *(histogram_value *) slot;
-  if (!pointer_set_contains (visited, hist))
+
+  if (!pointer_set_contains (visited, hist)
+      && hist->type != HIST_TYPE_TIME_PROFILE)
     {
       error ("dead histogram");
       dump_histogram_value (stderr, hist);
@@ -1919,12 +1932,14 @@ gimple_find_values_to_profile (histogram_values *values)
   gimple_stmt_iterator gsi;
   unsigned i;
   histogram_value hist = NULL;
-
   values->create (0);
+
   FOR_EACH_BB (bb)
     for (gsi = gsi_start_bb (bb); !gsi_end_p (gsi); gsi_next (&gsi))
       gimple_values_to_profile (gsi_stmt (gsi), values);
 
+  values->safe_push (gimple_alloc_histogram_value (cfun, HIST_TYPE_TIME_PROFILE, 0, 0));
+
   FOR_EACH_VEC_ELT (*values, i, hist)
     {
       switch (hist->type)
@@ -1949,6 +1964,10 @@ gimple_find_values_to_profile (histogram_values *values)
  	  hist->n_counters = 3;
 	  break;
 
+  case HIST_TYPE_TIME_PROFILE:
+    hist->n_counters = 1;
+    break;
+
 	case HIST_TYPE_AVERAGE:
 	  hist->n_counters = 2;
 	  break;

gcc/value-prof.h

@@ -34,6 +34,7 @@ enum hist_type
 			    called in indirect call */
   HIST_TYPE_AVERAGE,	/* Compute average value (sum of all values).  */
   HIST_TYPE_IOR,	/* Used to compute expected alignment.  */
+  HIST_TYPE_TIME_PROFILE, /* Used for time profile */
   HIST_TYPE_MAX
 };
 
@@ -54,6 +55,7 @@ struct histogram_value_t
     } hvalue;
   enum hist_type type;			/* Type of information to measure.  */
   unsigned n_counters;			/* Number of required counters.  */
+  struct function *fun;
   union
     {
       struct
@@ -97,6 +99,8 @@ extern void gimple_gen_pow2_profiler (histogram_value, unsigned, unsigned);
 extern void gimple_gen_one_value_profiler (histogram_value, unsigned, unsigned);
 extern void gimple_gen_ic_profiler (histogram_value, unsigned, unsigned);
 extern void gimple_gen_ic_func_profiler (void);
+extern void gimple_gen_time_profiler (unsigned, unsigned,
+                                      gimple_stmt_iterator &);
 extern void gimple_gen_const_delta_profiler (histogram_value,
 					     unsigned, unsigned);
 extern void gimple_gen_average_profiler (histogram_value, unsigned, unsigned);

libgcc/Makefile.in

@@ -858,7 +858,7 @@ LIBGCOV = _gcov _gcov_merge_add _gcov_merge_single _gcov_merge_delta \
     _gcov_execv _gcov_execvp _gcov_execve _gcov_reset _gcov_dump \
     _gcov_interval_profiler _gcov_pow2_profiler _gcov_one_value_profiler \
     _gcov_indirect_call_profiler _gcov_average_profiler _gcov_ior_profiler \
-    _gcov_merge_ior _gcov_indirect_call_profiler_v2
+    _gcov_merge_ior _gcov_time_profiler _gcov_indirect_call_profiler_v2 _gcov_merge_time_profile
 
 libgcov-objects = $(patsubst %,%$(objext),$(LIBGCOV))
 

libgcc/libgcov.c

@@ -80,6 +80,7 @@ void __gcov_merge_delta (gcov_type *counters  __attribute__ ((unused)),
 #include <sys/stat.h>
 #endif
 
+extern gcov_type function_counter ATTRIBUTE_HIDDEN;
 extern void gcov_clear (void) ATTRIBUTE_HIDDEN;
 extern void gcov_exit (void) ATTRIBUTE_HIDDEN;
 extern int gcov_dump_complete ATTRIBUTE_HIDDEN;
@@ -350,6 +351,10 @@ gcov_compute_histogram (struct gcov_summary *sum)
     }
 }
 
+
+/* Counter for first visit of each function.  */
+gcov_type function_counter;
+
 /* Dump the coverage counts. We merge with existing counts when
    possible, to avoid growing the .da files ad infinitum. We use this
    program's checksum to make sure we only accumulate whole program
@@ -974,6 +979,27 @@ __gcov_merge_ior (gcov_type *counters, unsigned n_counters)
 }
 #endif
 
+/* Time profiles are merged so that minimum from all valid (greater than zero)
+ * is stored. There could be a fork that creates new counters. To have
+ * the profile stable, we chosen to pick the smallest function visit time.  */
+
+#ifdef L_gcov_merge_time_profile
+void
+__gcov_merge_time_profile (gcov_type *counters, unsigned n_counters)
+{
+  unsigned int i;
+  gcov_type value;
+
+  for (i = 0; i < n_counters; i++)
+  {
+    value = gcov_read_counter ();
+
+    if (value && (!counters[i] || value < counters[i]))
+      counters[i] = value;
+  }
+}
+#endif /* L_gcov_merge_time_profile */
+
 #ifdef L_gcov_merge_single
 /* The profile merging function for choosing the most common value.
    It is given an array COUNTERS of N_COUNTERS old counters and it
@@ -1202,6 +1228,18 @@ __gcov_indirect_call_profiler_v2 (gcov_type value, void* cur_func)
 }
 #endif
 
+#ifdef L_gcov_time_profiler
+
+/* Sets corresponding COUNTERS if there is no value.  */
+
+void
+__gcov_time_profiler (gcov_type* counters)
+{
+  if (!counters[0])
+    counters[0] = ++function_counter;
+}
+#endif
+
 #ifdef L_gcov_average_profiler
 /* Increase corresponding COUNTER by VALUE.  FIXME: Perhaps we want
    to saturate up.  */