The intent of the phases was to have a high-level but mutually exclusive accounting...
authorLawrence Crowl <crowl@google.com>
Tue, 19 Jun 2012 01:30:31 +0000 (01:30 +0000)
committerLawrence Crowl <crowl@gcc.gnu.org>
Tue, 19 Jun 2012 01:30:31 +0000 (01:30 +0000)
The intent of the phases was to have a high-level but mutually exclusive
accounting of compile time.  We want to track compile time in a way that
tells us which conceptual phases are taking the most time.  That intent
is not currently satisfied.  This patch restores that intent.

Add code to verify that the sum of the phase times is less than the total
time, to detect when phases are overlapped.  A slight amount of leeway is
required due to time jitters.  This verification is done as the last step
in printing timevars so that any timevar information is not lost.

Rename the phases to be clearer about what they measure, so that they
are less likely to be modified to be overlapping.  The primary example
is to change TV_PHASE_GENERATE to TV_PHASE_LATE_ASM, meaning late work
on the assembly.  This name change avoids confusion n moving the timevar
start call after the call to lang_hooks.decls.final_write_globals, which
prevents overlapping phases.

Each implementation of lang_hooks.decls.final_write_globals, is responsible
for starting and stopping its own phases.  Each implementation currently has
a first phase of TV_PHASE_DEFERRED for front-end work deferred until after
parsing is complete.  The second phase has been renamed from TV_PHASE_CGRAPH
to TV_PHASE_OPT_GEN, to better reflect its use as the main optimization
and generation phase.  This phase accounts for 70%-80% of compilation time
during bootstrap.  The third phase is TV_PHASE_DBGINFO, except in cp/decl2.c,
where it is TV_PHASE_CHECK_DBGINFO because cc1plus mixes checking in with
debug info generation.  In langhooks.c, write_global_declarations was
using TV_PHASE_CHECK_DBGINFO, but it was doing no checking.  So, it now
uses TV_PHASE_DBGINFO.

The changes to LTO are significant.  First, initialization now uses
TV_PHASE_SETUP.  Reading files now uses TV_PHASE_STREAM_IN.  Writing files
now uses TV_PHASE_STREAM_OUT.  The remaining phase is TV_PHASE_OPT_GEN
(formerly TV_PHASE_CGRAPH).  Finally, because LTO is treated as a front
end, TV_PHASE_PARSING and TV_PARSE_GLOBAL active around it.  It is not
parsing, and so those timers should not be active.  Rather than make all
front ends manage them, we turn them off as the first thing in LTO and turn
them back on as the last thing.

Tested on x86_64.

Index: gcc/ChangeLog

2012-06-18  Lawrence Crowl  <crowl@google.com>

* timevar.def (TV_PHASE_GENERATE): Rename to TV_PHASE_LATE_ASM.
(TV_PHASE_CGRAPH): Rename to TV_PHASE_OPT_GEN.
(TV_PHASE_STREAM_IN): New.
(TV_PHASE_STREAM_OUT): New.
* timevar.c (validate_phases): New.
(timevar_print): Call validate_phases.
* c-decl.c (c_write_global_declarations): Rename use of TV_PHASE_CGRAPH
to TV_PHASE_OPT_GEN.
* langhooks.c (write_global_declarations): Rename use of
TV_PHASE_CGRAPH to TV_PHASE_OPT_GEN.  Use TV_PHASE_DBGINFO instead of
TV_PHASE_CHECK_DBGINFO.
* toplev.c (compile_file): Rename use of TV_PHASE_GENERATE to
TV_PHASE_LATE_ASM.  Move start of TV_PHASE_LATE_ASM to after call to
lang_hooks.decls.final_write_globals.

Index: gcc/cp/ChangeLog

2012-06-18  Lawrence Crowl  <crowl@google.com>

* decl2.c (cp_write_global_declarations): Rename use of TV_PHASE_CGRAPH
to TV_PHASE_OPT_GEN.

Index: gcc/lto/ChangeLog

2012-06-18  Lawrence Crowl  <crowl@google.com>

        * lto.c (do_whole_program_analysis):  Rename use of TV_PHASE_CGRAPH to
TV_PHASE_OPT_GEN.  Use new timevar TV_PHASE_STREAM_OUT around the call
to lto_wpa_write_files.
(lto_main):  Rename use of TV_PHASE_CGRAPH to TV_PHASE_OPT_GEN.  Move
start of TV_PHASE_OPT_GEN to include call to materialize_cgraph.  Use
TV_PHASE_SETUP for the call to lto_init.  Use new timevar
TV_PHASE_STREAM_IN around the call to read_cgraph_and_symbols.
Turn TV_PHASE_PARSING off then back on again, because LTO is pretending
to be a front end, but is not one.

From-SVN: r188765

gcc/ChangeLog
gcc/c-decl.c
gcc/cp/ChangeLog
gcc/cp/decl2.c
gcc/langhooks.c
gcc/lto/ChangeLog
gcc/lto/lto.c
gcc/timevar.c
gcc/timevar.def
gcc/toplev.c

index 348185f8dba6cf707f71e4a65d537a1621655bd4..0055ebf90b171937f06bfabca985466f30434e3a 100644 (file)
@@ -1,3 +1,20 @@
+2012-06-18  Lawrence Crowl  <crowl@google.com>
+
+       * timevar.def (TV_PHASE_GENERATE): Rename to TV_PHASE_LATE_ASM.
+       (TV_PHASE_CGRAPH): Rename to TV_PHASE_OPT_GEN.
+       (TV_PHASE_STREAM_IN): New.
+       (TV_PHASE_STREAM_OUT): New.
+       * timevar.c (validate_phases): New.
+       (timevar_print): Call validate_phases.
+       * c-decl.c (c_write_global_declarations): Rename use of TV_PHASE_CGRAPH
+       to TV_PHASE_OPT_GEN.
+       * langhooks.c (write_global_declarations): Rename use of
+       TV_PHASE_CGRAPH to TV_PHASE_OPT_GEN.  Use TV_PHASE_DBGINFO instead of
+       TV_PHASE_CHECK_DBGINFO.
+       * toplev.c (compile_file): Rename use of TV_PHASE_GENERATE to
+       TV_PHASE_LATE_ASM.  Move start of TV_PHASE_LATE_ASM to after call to
+       lang_hooks.decls.final_write_globals.
+
 2012-06-18  David Edelshn  <dje.gcc@gmail.com>
 
        * config/rs6000/aix52.h (TARGET_EXTRA_BUILTINS): Define as 0.
index 86add1402b4ff64cbd6b6013759480432d716b90..9622b1207d46a0369af26349b6988a68fb97409d 100644 (file)
@@ -10101,13 +10101,13 @@ c_write_global_declarations (void)
   c_write_global_declarations_1 (BLOCK_VARS (ext_block));
 
   timevar_stop (TV_PHASE_DEFERRED);
-  timevar_start (TV_PHASE_CGRAPH);
+  timevar_start (TV_PHASE_OPT_GEN);
 
   /* We're done parsing; proceed to optimize and emit assembly.
      FIXME: shouldn't be the front end's responsibility to call this.  */
   finalize_compilation_unit ();
 
-  timevar_stop (TV_PHASE_CGRAPH);
+  timevar_stop (TV_PHASE_OPT_GEN);
   timevar_start (TV_PHASE_DBGINFO);
 
   /* After cgraph has had a chance to emit everything that's going to
index 590eadd202fe747463400730909592ddebfcbde6..b45077525cc5981b41f9b918e6ae4cbb6be500cf 100644 (file)
@@ -1,3 +1,8 @@
+2012-06-18  Lawrence Crowl  <crowl@google.com>
+
+       * decl2.c (cp_write_global_declarations): Rename use of TV_PHASE_CGRAPH
+       to TV_PHASE_OPT_GEN.
+
 2012-06-18  Steven Bosscher  <steven@gcc.gnu.org>
 
        * decl.c (finish_function): Remove code conditional on VMS_TARGET.
index 2e3c9a633625275cf01c3e3a4b73187e5d6b6437..d8c72606f2ec2a3283ff13dde0e41df59d7ff958 100644 (file)
@@ -4019,11 +4019,11 @@ cp_write_global_declarations (void)
   candidates = collect_candidates_for_java_method_aliases ();
 
   timevar_stop (TV_PHASE_DEFERRED);
-  timevar_start (TV_PHASE_CGRAPH);
+  timevar_start (TV_PHASE_OPT_GEN);
 
   finalize_compilation_unit ();
 
-  timevar_stop (TV_PHASE_CGRAPH);
+  timevar_stop (TV_PHASE_OPT_GEN);
   timevar_start (TV_PHASE_CHECK_DBGINFO);
 
   /* Now, issue warnings about static, but not defined, functions,
index 46c19c33a69c50c0b5407116d90864c0f5cf3bee..a34733f13b30ab4bc3ef0b022a3b62f5fa4c5db0 100644 (file)
@@ -317,15 +317,15 @@ write_global_declarations (void)
   check_global_declarations (vec, len);
   timevar_stop (TV_PHASE_DEFERRED);
 
-  timevar_start (TV_PHASE_CGRAPH);
+  timevar_start (TV_PHASE_OPT_GEN);
   /* This lang hook is dual-purposed, and also finalizes the
      compilation unit.  */
   finalize_compilation_unit ();
-  timevar_stop (TV_PHASE_CGRAPH);
+  timevar_stop (TV_PHASE_OPT_GEN);
 
-  timevar_start (TV_PHASE_CHECK_DBGINFO);
+  timevar_start (TV_PHASE_DBGINFO);
   emit_debug_global_declarations (vec, len);
-  timevar_stop (TV_PHASE_CHECK_DBGINFO);
+  timevar_stop (TV_PHASE_DBGINFO);
 
   /* Clean up.  */
   free (vec);
index 06774d833b009b3e2cf4e5c15faae7ca844ee37e..3f025dc83630d35911d634eea4236388f4d62f2f 100644 (file)
@@ -1,3 +1,15 @@
+2012-06-18  Lawrence Crowl  <crowl@google.com>
+
+        * lto.c (do_whole_program_analysis):  Rename use of TV_PHASE_CGRAPH to
+       TV_PHASE_OPT_GEN.  Use new timevar TV_PHASE_STREAM_OUT around the call
+       to lto_wpa_write_files.
+       (lto_main):  Rename use of TV_PHASE_CGRAPH to TV_PHASE_OPT_GEN.  Move
+       start of TV_PHASE_OPT_GEN to include call to materialize_cgraph.  Use
+       TV_PHASE_SETUP for the call to lto_init.  Use new timevar
+       TV_PHASE_STREAM_IN around the call to read_cgraph_and_symbols.
+       Turn TV_PHASE_PARSING off then back on again, because LTO is pretending
+       to be a front end, but is not one.
+
 2012-05-18  Jan Hubicka  <jh@suse.cz>
 
        * lto.c (lto_materialize_constructors_and_inits): Remove.
index b94c8a7f8694dc10be56a5cd74cb35182e705b4e..df5c3df2ef3e4001677fed7af017cf686cd0b133 100644 (file)
@@ -1935,7 +1935,8 @@ materialize_cgraph (void)
 static void
 do_whole_program_analysis (void)
 {
-  timevar_start (TV_PHASE_CGRAPH);
+  timevar_start (TV_PHASE_OPT_GEN);
+
   /* Note that since we are in WPA mode, materialize_cgraph will not
      actually read in all the function bodies.  It only materializes
      the decls and cgraph nodes so that analysis can be performed.  */
@@ -1979,23 +1980,27 @@ do_whole_program_analysis (void)
   else
     lto_balanced_map ();
 
+  timevar_stop (TV_PHASE_OPT_GEN);
+  timevar_start (TV_PHASE_STREAM_OUT);
+
   if (!quiet_flag)
     {
       fprintf (stderr, "\nStreaming out");
       fflush (stderr);
     }
   lto_wpa_write_files ();
-  ggc_collect ();
   if (!quiet_flag)
     fprintf (stderr, "\n");
 
+  timevar_stop (TV_PHASE_STREAM_OUT);
+
+  ggc_collect ();
   if (post_ipa_mem_report)
     {
       fprintf (stderr, "Memory consumption after IPA\n");
       dump_memory_report (false);
     }
 
-  timevar_stop (TV_PHASE_CGRAPH);
   /* Show the LTO report before launching LTRANS.  */
   if (flag_lto_report)
     print_lto_report ();
@@ -2075,13 +2080,28 @@ lto_init (void)
 void
 lto_main (void)
 {
+  /* LTO is called as a front end, even though it is not a front end.
+     Because it is called as a front end, TV_PHASE_PARSING and
+     TV_PARSE_GLOBAL are active, and we need to turn them off while
+     doing LTO.  Later we turn them back on so they are active up in
+     toplev.c.  */
+  timevar_pop (TV_PARSE_GLOBAL);
+  timevar_stop (TV_PHASE_PARSING);
+
+  timevar_start (TV_PHASE_SETUP);
+
   /* Initialize the LTO front end.  */
   lto_init ();
 
+  timevar_stop (TV_PHASE_SETUP);
+  timevar_start (TV_PHASE_STREAM_IN);
+
   /* Read all the symbols and call graph from all the files in the
      command line.  */
   read_cgraph_and_symbols (num_in_fnames, in_fnames);
 
+  timevar_stop (TV_PHASE_STREAM_IN);
+
   if (!seen_error ())
     {
       /* If WPA is enabled analyze the whole call graph and create an
@@ -2091,13 +2111,15 @@ lto_main (void)
        do_whole_program_analysis ();
       else
        {
+         timevar_start (TV_PHASE_OPT_GEN);
+
          materialize_cgraph ();
 
          /* Let the middle end know that we have read and merged all of
             the input files.  */ 
-         timevar_start (TV_PHASE_CGRAPH);
          compile ();
-         timevar_stop (TV_PHASE_CGRAPH);
+
+         timevar_stop (TV_PHASE_OPT_GEN);
 
          /* FIXME lto, if the processes spawned by WPA fail, we miss
             the chance to print WPA's report, so WPA will call
@@ -2108,6 +2130,10 @@ lto_main (void)
            print_lto_report ();
        }
     }
+
+  /* Here we make LTO pretend to be a parser.  */
+  timevar_start (TV_PHASE_PARSING);
+  timevar_push (TV_PARSE_GLOBAL);
 }
 
 #include "gt-lto-lto.h"
index 96eb92ae3cd76ad3289dfba255fdea8b0caf0bc4..2d1fe72ce99d94cd73d62d1698c2e2f16e13e628 100644 (file)
@@ -421,6 +421,57 @@ timevar_cond_stop (timevar_id_t timevar, bool running)
 }
 
 
+/* Validate that phase times are consistent.  */
+
+static void
+validate_phases (FILE *fp)
+{
+  unsigned int /* timevar_id_t */ id;
+  struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
+  double phase_user = 0.0;
+  double phase_sys = 0.0;
+  double phase_wall = 0.0;
+  unsigned phase_ggc_mem = 0;
+  static char phase_prefix[] = "phase ";
+  const double tolerance = 1.000001;  /* One part in a million.  */
+
+  for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
+    {
+      struct timevar_def *tv = &timevars[(timevar_id_t) id];
+
+      /* Don't evaluate timing variables that were never used.  */
+      if (!tv->used)
+       continue;
+
+      if (strncmp (tv->name, phase_prefix, sizeof phase_prefix - 1) == 0)
+       {
+         phase_user += tv->elapsed.user;
+         phase_sys += tv->elapsed.sys;
+         phase_wall += tv->elapsed.wall;
+         phase_ggc_mem += tv->elapsed.ggc_mem;
+       }
+    }
+
+  if (phase_user > total->user * tolerance
+      || phase_sys > total->sys * tolerance
+      || phase_wall > total->wall * tolerance
+      || phase_ggc_mem > total->ggc_mem * tolerance)
+    {
+
+      fprintf (fp, "Timing error: total of phase timers exceeds total time.\n");
+      if (phase_user > total->user)
+       fprintf (fp, "user    %24.18e > %24.18e\n", phase_user, total->user);
+      if (phase_sys > total->sys)
+       fprintf (fp, "sys     %24.18e > %24.18e\n", phase_sys, total->sys);
+      if (phase_wall > total->wall)
+       fprintf (fp, "wall    %24.18e > %24.18e\n", phase_wall, total->wall);
+      if (phase_ggc_mem > total->ggc_mem)
+       fprintf (fp, "ggc_mem %24u > %24u\n", phase_ggc_mem, total->ggc_mem);
+      gcc_unreachable ();
+    }
+}
+
+
 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
    a special meaning -- it's considered to be the total elapsed time,
    for normalizing the others, and is displayed last.  */
@@ -535,6 +586,8 @@ timevar_print (FILE *fp)
 
 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
          || defined (HAVE_WALL_TIME) */
+
+  validate_phases (fp);
 }
 
 /* Prints a message to stderr stating that time elapsed in STR is
index 1f5ea2a81bd1ac734e89bd1289ff6e23f9696096..57d9e3f8fd7a9e670518baabe15c130c06afd786 100644 (file)
 
 /* The total execution time.  */
 DEFTIMEVAR (TV_TOTAL                 , "total time")
+/* The compiler phases.  These must be mutually exclusive.
+   Ideally, they would sum to near the total time.  */
 DEFTIMEVAR (TV_PHASE_SETUP           , "phase setup")
 DEFTIMEVAR (TV_PHASE_PARSING         , "phase parsing")
 DEFTIMEVAR (TV_PHASE_DEFERRED        , "phase lang. deferred")
-DEFTIMEVAR (TV_PHASE_CGRAPH          , "phase cgraph")
+DEFTIMEVAR (TV_PHASE_OPT_GEN         , "phase opt and generate")
 DEFTIMEVAR (TV_PHASE_DBGINFO         , "phase debug info")
 DEFTIMEVAR (TV_PHASE_CHECK_DBGINFO   , "phase check & debug info")
-DEFTIMEVAR (TV_PHASE_GENERATE        , "phase generate")
+DEFTIMEVAR (TV_PHASE_LATE_ASM        , "phase last asm")
+DEFTIMEVAR (TV_PHASE_STREAM_IN       , "phase stream in")
+DEFTIMEVAR (TV_PHASE_STREAM_OUT      , "phase stream out")
 DEFTIMEVAR (TV_PHASE_FINALIZE        , "phase finalize")
 
 /* Concurrent timers, indicated by "|".  */
index 3f5e61be672976a983547e5de5c72c7f4e9b01f7..2eb75f1b9d68e7418e1524972afaa86a5fb10764 100644 (file)
@@ -558,18 +558,15 @@ compile_file (void)
   if (flag_syntax_only || flag_wpa)
     return;
 
-  timevar_start (TV_PHASE_GENERATE);
-
   ggc_protect_identifiers = false;
 
   /* This must also call finalize_compilation_unit.  */
   lang_hooks.decls.final_write_globals ();
 
   if (seen_error ())
-    {
-      timevar_stop (TV_PHASE_GENERATE);
-      return;
-    }
+    return;
+
+  timevar_start (TV_PHASE_LATE_ASM);
 
   /* Compilation unit is finalized.  When producing non-fat LTO object, we are
      basically finished.  */
@@ -670,7 +667,7 @@ compile_file (void)
      assembly file after this point.  */
   targetm.asm_out.file_end ();
 
-  timevar_stop (TV_PHASE_GENERATE);
+  timevar_stop (TV_PHASE_LATE_ASM);
 }
 
 /* Print version information to FILE.