gcc/timevar.c

   1 /* Timing variables for measuring compiler performance.
   2    Copyright (C) 2000-2021 Free Software Foundation, Inc.
   3    Contributed by Alex Samuel <samuel@codesourcery.com>
   4
   5 This file is part of GCC.
   6
   7 GCC is free software; you can redistribute it and/or modify it under
   8 the terms of the GNU General Public License as published by the Free
   9 Software Foundation; either version 3, or (at your option) any later
  10 version.
  11
  12 GCC is distributed in the hope that it will be useful, but WITHOUT ANY
  13 WARRANTY; without even the implied warranty of MERCHANTABILITY or
  14 FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  15 for more details.
  16
  17 You should have received a copy of the GNU General Public License
  18 along with GCC; see the file COPYING3.  If not see
  19 <http://www.gnu.org/licenses/>.  */
  20
  21 #include "config.h"
  22 #include "system.h"
  23 #include "coretypes.h"
  24 #include "timevar.h"
  25 #include "options.h"
  26
  27 #ifndef HAVE_CLOCK_T
  28 typedef int clock_t;
  29 #endif
  30
  31 #ifndef HAVE_STRUCT_TMS
  32 struct tms
  33 {
  34   clock_t tms_utime;
  35   clock_t tms_stime;
  36   clock_t tms_cutime;
  37   clock_t tms_cstime;
  38 };
  39 #endif
  40
  41 #ifndef RUSAGE_SELF
  42 # define RUSAGE_SELF 0
  43 #endif
  44
  45 /* Calculation of scale factor to convert ticks to microseconds.
  46    We mustn't use CLOCKS_PER_SEC except with clock().  */
  47 #if HAVE_SYSCONF && defined _SC_CLK_TCK
  48 # define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
  49 #else
  50 # ifdef CLK_TCK
  51 #  define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
  52 # else
  53 #  ifdef HZ
  54 #   define TICKS_PER_SECOND HZ  /* traditional UNIX */
  55 #  else
  56 #   define TICKS_PER_SECOND 100 /* often the correct value */
  57 #  endif
  58 # endif
  59 #endif
  60
  61 /* Prefer times to getrusage to clock (each gives successively less
  62    information).  */
  63 #ifdef HAVE_TIMES
  64 # if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
  65   extern clock_t times (struct tms *);
  66 # endif
  67 # define USE_TIMES
  68 # define HAVE_USER_TIME
  69 # define HAVE_SYS_TIME
  70 # define HAVE_WALL_TIME
  71 #else
  72 #ifdef HAVE_GETRUSAGE
  73 # if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
  74   extern int getrusage (int, struct rusage *);
  75 # endif
  76 # define USE_GETRUSAGE
  77 # define HAVE_USER_TIME
  78 # define HAVE_SYS_TIME
  79 #else
  80 #ifdef HAVE_CLOCK
  81 # if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
  82   extern clock_t clock (void);
  83 # endif
  84 # define USE_CLOCK
  85 # define HAVE_USER_TIME
  86 #endif
  87 #endif
  88 #endif
  89
  90 /* libc is very likely to have snuck a call to sysconf() into one of
  91    the underlying constants, and that can be very slow, so we have to
  92    precompute them.  Whose wonderful idea was it to make all those
  93    _constants_ variable at run time, anyway?  */
  94 #ifdef USE_TIMES
  95 static double ticks_to_msec;
  96 #define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
  97 #endif
  98
  99 #ifdef USE_CLOCK
 100 static double clocks_to_msec;
 101 #define CLOCKS_TO_MSEC (1 / (double)CLOCKS_PER_SEC)
 102 #endif
 103
 104 /* Non-NULL if timevars should be used.  In GCC, this happens with
 105    the -ftime-report flag.  */
 106
 107 timer *g_timer;
 108
 109 /* Total amount of memory allocated by garbage collector.  */
 110
 111 size_t timevar_ggc_mem_total;
 112
 113 /* The amount of memory that will cause us to report the timevar even
 114    if the time spent is not significant.  */
 115
 116 #define GGC_MEM_BOUND (1 << 20)
 117
 118 /* See timevar.h for an explanation of timing variables.  */
 119
 120 static void get_time (struct timevar_time_def *);
 121 static void timevar_accumulate (struct timevar_time_def *,
 122                                 struct timevar_time_def *,
 123                                 struct timevar_time_def *);
 124
 125 /* The implementation of timing events for jit client code, allowing
 126    arbitrary named items to appear on the timing stack.  */
 127
 128 class timer::named_items
 129 {
 130  public:
 131   named_items (timer *t);
 132   ~named_items ();
 133
 134   void push (const char *item_name);
 135   void pop ();
 136   void print (FILE *fp, const timevar_time_def *total);
 137
 138  private:
 139   /* Which timer instance does this relate to?  */
 140   timer *m_timer;
 141
 142   /* Dictionary, mapping from item names to timevar_def.
 143      Note that currently we merely store/compare the raw string
 144      pointers provided by client code; we don't take a copy,
 145      or use strcmp.  */
 146   hash_map <const char *, timer::timevar_def> m_hash_map;
 147
 148   /* The order in which items were originally inserted.  */
 149   auto_vec <const char *> m_names;
 150 };
 151
 152 /* The constructor for class timer::named_items.  */
 153
 154 timer::named_items::named_items (timer *t)
 155 : m_timer (t),
 156   m_hash_map (),
 157   m_names ()
 158 {
 159 }
 160
 161 /* The destructor for class timer::named_items.  */
 162
 163 timer::named_items::~named_items ()
 164 {
 165 }
 166
 167 /* Push the named item onto the timer stack.  */
 168
 169 void
 170 timer::named_items::push (const char *item_name)
 171 {
 172   gcc_assert (item_name);
 173
 174   bool existed;
 175   timer::timevar_def *def = &m_hash_map.get_or_insert (item_name, &existed);
 176   if (!existed)
 177     {
 178       def->elapsed.user = 0;
 179       def->elapsed.sys = 0;
 180       def->elapsed.wall = 0;
 181       def->name = item_name;
 182       def->standalone = 0;
 183       m_names.safe_push (item_name);
 184     }
 185   m_timer->push_internal (def);
 186 }
 187
 188 /* Pop the top item from the timer stack.  */
 189
 190 void
 191 timer::named_items::pop ()
 192 {
 193   m_timer->pop_internal ();
 194 }
 195
 196 /* Print the given client item.  Helper function for timer::print.  */
 197
 198 void
 199 timer::named_items::print (FILE *fp, const timevar_time_def *total)
 200 {
 201   fprintf (fp, "Client items:\n");
 202   for (const char *item_name : m_names)
 203     {
 204       timer::timevar_def *def = m_hash_map.get (item_name);
 205       gcc_assert (def);
 206       m_timer->print_row (fp, total, def->name, def->elapsed);
 207     }
 208 }
 209
 210 /* Fill the current times into TIME.  The definition of this function
 211    also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
 212    HAVE_WALL_TIME macros.  */
 213
 214 static void
 215 get_time (struct timevar_time_def *now)
 216 {
 217   now->user = 0;
 218   now->sys  = 0;
 219   now->wall = 0;
 220   now->ggc_mem = timevar_ggc_mem_total;
 221
 222   {
 223 #ifdef USE_TIMES
 224     struct tms tms;
 225     now->wall = times (&tms)  * ticks_to_msec;
 226     now->user = tms.tms_utime * ticks_to_msec;
 227     now->sys  = tms.tms_stime * ticks_to_msec;
 228 #endif
 229 #ifdef USE_GETRUSAGE
 230     struct rusage rusage;
 231     getrusage (RUSAGE_SELF, &rusage);
 232     now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
 233     now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
 234 #endif
 235 #ifdef USE_CLOCK
 236     now->user = clock () * clocks_to_msec;
 237 #endif
 238   }
 239 }
 240
 241 /* Add the difference between STOP_TIME and START_TIME to TIMER.  */
 242
 243 static void
 244 timevar_accumulate (struct timevar_time_def *timer,
 245                     struct timevar_time_def *start_time,
 246                     struct timevar_time_def *stop_time)
 247 {
 248   timer->user += stop_time->user - start_time->user;
 249   timer->sys += stop_time->sys - start_time->sys;
 250   timer->wall += stop_time->wall - start_time->wall;
 251   timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
 252 }
 253
 254 /* Class timer's constructor.  */
 255
 256 timer::timer () :
 257   m_stack (NULL),
 258   m_unused_stack_instances (NULL),
 259   m_start_time (),
 260   m_jit_client_items (NULL)
 261 {
 262   /* Zero all elapsed times.  */
 263   memset (m_timevars, 0, sizeof (m_timevars));
 264
 265   /* Initialize the names of timing variables.  */
 266 #define DEFTIMEVAR(identifier__, name__) \
 267   m_timevars[identifier__].name = name__;
 268 #include "timevar.def"
 269 #undef DEFTIMEVAR
 270
 271   /* Initialize configuration-specific state.
 272      Ideally this would be one-time initialization.  */
 273 #ifdef USE_TIMES
 274   ticks_to_msec = TICKS_TO_MSEC;
 275 #endif
 276 #ifdef USE_CLOCK
 277   clocks_to_msec = CLOCKS_TO_MSEC;
 278 #endif
 279 }
 280
 281 /* Class timer's destructor.  */
 282
 283 timer::~timer ()
 284 {
 285   timevar_stack_def *iter, *next;
 286
 287   for (iter = m_stack; iter; iter = next)
 288     {
 289       next = iter->next;
 290       free (iter);
 291     }
 292   for (iter = m_unused_stack_instances; iter; iter = next)
 293     {
 294       next = iter->next;
 295       free (iter);
 296     }
 297   for (unsigned i = 0; i < TIMEVAR_LAST; ++i)
 298     delete m_timevars[i].children;
 299
 300   delete m_jit_client_items;
 301 }
 302
 303 /* Initialize timing variables.  */
 304
 305 void
 306 timevar_init (void)
 307 {
 308   if (g_timer)
 309     return;
 310
 311   g_timer = new timer ();
 312 }
 313
 314 /* Push TIMEVAR onto the timing stack.  No further elapsed time is
 315    attributed to the previous topmost timing variable on the stack;
 316    subsequent elapsed time is attributed to TIMEVAR, until it is
 317    popped or another element is pushed on top.
 318
 319    TIMEVAR cannot be running as a standalone timer.  */
 320
 321 void
 322 timer::push (timevar_id_t timevar)
 323 {
 324   struct timevar_def *tv = &m_timevars[timevar];
 325   push_internal (tv);
 326 }
 327
 328 /* Push TV onto the timing stack, either one of the builtin ones
 329    for a timevar_id_t, or one provided by client code to libgccjit.  */
 330
 331 void
 332 timer::push_internal (struct timevar_def *tv)
 333 {
 334   struct timevar_stack_def *context;
 335   struct timevar_time_def now;
 336
 337   gcc_assert (tv);
 338
 339   /* Mark this timing variable as used.  */
 340   tv->used = 1;
 341
 342   /* Can't push a standalone timer.  */
 343   gcc_assert (!tv->standalone);
 344
 345   /* What time is it?  */
 346   get_time (&now);
 347
 348   /* If the stack isn't empty, attribute the current elapsed time to
 349      the old topmost element.  */
 350   if (m_stack)
 351     timevar_accumulate (&m_stack->timevar->elapsed, &m_start_time, &now);
 352
 353   /* Reset the start time; from now on, time is attributed to
 354      TIMEVAR.  */
 355   m_start_time = now;
 356
 357   /* See if we have a previously-allocated stack instance.  If so,
 358      take it off the list.  If not, malloc a new one.  */
 359   if (m_unused_stack_instances != NULL)
 360     {
 361       context = m_unused_stack_instances;
 362       m_unused_stack_instances = m_unused_stack_instances->next;
 363     }
 364   else
 365     context = XNEW (struct timevar_stack_def);
 366
 367   /* Fill it in and put it on the stack.  */
 368   context->timevar = tv;
 369   context->next = m_stack;
 370   m_stack = context;
 371 }
 372
 373 /* Pop the topmost timing variable element off the timing stack.  The
 374    popped variable must be TIMEVAR.  Elapsed time since the that
 375    element was pushed on, or since it was last exposed on top of the
 376    stack when the element above it was popped off, is credited to that
 377    timing variable.  */
 378
 379 void
 380 timer::pop (timevar_id_t timevar)
 381 {
 382   gcc_assert (&m_timevars[timevar] == m_stack->timevar);
 383
 384   pop_internal ();
 385 }
 386
 387 /* Pop the topmost item from the stack, either one of the builtin ones
 388    for a timevar_id_t, or one provided by client code to libgccjit.  */
 389
 390 void
 391 timer::pop_internal ()
 392 {
 393   struct timevar_time_def now;
 394   struct timevar_stack_def *popped = m_stack;
 395
 396   /* What time is it?  */
 397   get_time (&now);
 398
 399   /* Attribute the elapsed time to the element we're popping.  */
 400   timevar_accumulate (&popped->timevar->elapsed, &m_start_time, &now);
 401
 402   /* Take the item off the stack.  */
 403   m_stack = m_stack->next;
 404
 405   /* Record the elapsed sub-time to the parent as well.  */
 406   if (m_stack && time_report_details)
 407     {
 408       if (! m_stack->timevar->children)
 409         m_stack->timevar->children = new child_map_t (5);
 410       bool existed_p;
 411       timevar_time_def &time
 412         = m_stack->timevar->children->get_or_insert (popped->timevar, &existed_p);
 413       if (! existed_p)
 414         memset (&time, 0, sizeof (timevar_time_def));
 415       timevar_accumulate (&time, &m_start_time, &now);
 416     }
 417
 418   /* Reset the start time; from now on, time is attributed to the
 419      element just exposed on the stack.  */
 420   m_start_time = now;
 421
 422   /* Don't delete the stack element; instead, add it to the list of
 423      unused elements for later use.  */
 424   popped->next = m_unused_stack_instances;
 425   m_unused_stack_instances = popped;
 426 }
 427
 428 /* Start timing TIMEVAR independently of the timing stack.  Elapsed
 429    time until timevar_stop is called for the same timing variable is
 430    attributed to TIMEVAR.  */
 431
 432 void
 433 timevar_start (timevar_id_t timevar)
 434 {
 435   if (!g_timer)
 436     return;
 437
 438   g_timer->start (timevar);
 439 }
 440
 441 /* See timevar_start above.  */
 442
 443 void
 444 timer::start (timevar_id_t timevar)
 445 {
 446   struct timevar_def *tv = &m_timevars[timevar];
 447
 448   /* Mark this timing variable as used.  */
 449   tv->used = 1;
 450
 451   /* Don't allow the same timing variable to be started more than
 452      once.  */
 453   gcc_assert (!tv->standalone);
 454   tv->standalone = 1;
 455
 456   get_time (&tv->start_time);
 457 }
 458
 459 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 460    is attributed to it.  */
 461
 462 void
 463 timevar_stop (timevar_id_t timevar)
 464 {
 465   if (!g_timer)
 466     return;
 467
 468   g_timer->stop (timevar);
 469 }
 470
 471 /* See timevar_stop above.  */
 472
 473 void
 474 timer::stop (timevar_id_t timevar)
 475 {
 476   struct timevar_def *tv = &m_timevars[timevar];
 477   struct timevar_time_def now;
 478
 479   /* TIMEVAR must have been started via timevar_start.  */
 480   gcc_assert (tv->standalone);
 481   tv->standalone = 0; /* Enable a restart.  */
 482
 483   get_time (&now);
 484   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 485 }
 486
 487
 488 /* Conditionally start timing TIMEVAR independently of the timing stack.
 489    If the timer is already running, leave it running and return true.
 490    Otherwise, start the timer and return false.
 491    Elapsed time until the corresponding timevar_cond_stop
 492    is called for the same timing variable is attributed to TIMEVAR.  */
 493
 494 bool
 495 timevar_cond_start (timevar_id_t timevar)
 496 {
 497   if (!g_timer)
 498     return false;
 499
 500   return g_timer->cond_start (timevar);
 501 }
 502
 503 /* See timevar_cond_start above.  */
 504
 505 bool
 506 timer::cond_start (timevar_id_t timevar)
 507 {
 508   struct timevar_def *tv = &m_timevars[timevar];
 509
 510   /* Mark this timing variable as used.  */
 511   tv->used = 1;
 512
 513   if (tv->standalone)
 514     return true;  /* The timevar is already running.  */
 515
 516   /* Don't allow the same timing variable
 517      to be unconditionally started more than once.  */
 518   tv->standalone = 1;
 519
 520   get_time (&tv->start_time);
 521   return false;  /* The timevar was not already running.  */
 522 }
 523
 524 /* Conditionally stop timing TIMEVAR.  The RUNNING parameter must come
 525    from the return value of a dynamically matching timevar_cond_start.
 526    If the timer had already been RUNNING, do nothing.  Otherwise, time
 527    elapsed since timevar_cond_start was called is attributed to it.  */
 528
 529 void
 530 timevar_cond_stop (timevar_id_t timevar, bool running)
 531 {
 532   if (!g_timer || running)
 533     return;
 534
 535   g_timer->cond_stop (timevar);
 536 }
 537
 538 /* See timevar_cond_stop above.  */
 539
 540 void
 541 timer::cond_stop (timevar_id_t timevar)
 542 {
 543   struct timevar_def *tv;
 544   struct timevar_time_def now;
 545
 546   tv = &m_timevars[timevar];
 547
 548   /* TIMEVAR must have been started via timevar_cond_start.  */
 549   gcc_assert (tv->standalone);
 550   tv->standalone = 0; /* Enable a restart.  */
 551
 552   get_time (&now);
 553   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 554 }
 555
 556 /* Push the named item onto the timing stack.  */
 557
 558 void
 559 timer::push_client_item (const char *item_name)
 560 {
 561   gcc_assert (item_name);
 562
 563   /* Lazily create the named_items instance.  */
 564   if (!m_jit_client_items)
 565     m_jit_client_items = new named_items (this);
 566
 567   m_jit_client_items->push (item_name);
 568 }
 569
 570 /* Pop the top-most client item from the timing stack.  */
 571
 572 void
 573 timer::pop_client_item ()
 574 {
 575   gcc_assert (m_jit_client_items);
 576   m_jit_client_items->pop ();
 577 }
 578
 579 /* Validate that phase times are consistent.  */
 580
 581 void
 582 timer::validate_phases (FILE *fp) const
 583 {
 584   unsigned int /* timevar_id_t */ id;
 585   const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
 586   double phase_user = 0.0;
 587   double phase_sys = 0.0;
 588   double phase_wall = 0.0;
 589   size_t phase_ggc_mem = 0;
 590   static char phase_prefix[] = "phase ";
 591   const double tolerance = 1.000001;  /* One part in a million.  */
 592
 593   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 594     {
 595       const timevar_def *tv = &m_timevars[(timevar_id_t) id];
 596
 597       /* Don't evaluate timing variables that were never used.  */
 598       if (!tv->used)
 599         continue;
 600
 601       if (startswith (tv->name, phase_prefix))
 602         {
 603           phase_user += tv->elapsed.user;
 604           phase_sys += tv->elapsed.sys;
 605           phase_wall += tv->elapsed.wall;
 606           phase_ggc_mem += tv->elapsed.ggc_mem;
 607         }
 608     }
 609
 610   if (phase_user > total->user * tolerance
 611       || phase_sys > total->sys * tolerance
 612       || phase_wall > total->wall * tolerance
 613       || phase_ggc_mem > total->ggc_mem * tolerance)
 614     {
 615
 616       fprintf (fp, "Timing error: total of phase timers exceeds total time.\n");
 617       if (phase_user > total->user)
 618         fprintf (fp, "user    %24.18e > %24.18e\n", phase_user, total->user);
 619       if (phase_sys > total->sys)
 620         fprintf (fp, "sys     %24.18e > %24.18e\n", phase_sys, total->sys);
 621       if (phase_wall > total->wall)
 622         fprintf (fp, "wall    %24.18e > %24.18e\n", phase_wall, total->wall);
 623       if (phase_ggc_mem > total->ggc_mem)
 624         fprintf (fp, "ggc_mem %24lu > %24lu\n", (unsigned long)phase_ggc_mem,
 625                  (unsigned long)total->ggc_mem);
 626       gcc_unreachable ();
 627     }
 628 }
 629
 630 /* Helper function for timer::print.  */
 631
 632 void
 633 timer::print_row (FILE *fp,
 634                   const timevar_time_def *total,
 635                   const char *name, const timevar_time_def &elapsed)
 636 {
 637   /* The timing variable name.  */
 638   fprintf (fp, " %-35s:", name);
 639
 640 #ifdef HAVE_USER_TIME
 641   /* Print user-mode time for this process.  */
 642   fprintf (fp, "%7.2f (%3.0f%%)",
 643            elapsed.user,
 644            (total->user == 0 ? 0 : elapsed.user / total->user) * 100);
 645 #endif /* HAVE_USER_TIME */
 646
 647 #ifdef HAVE_SYS_TIME
 648   /* Print system-mode time for this process.  */
 649   fprintf (fp, "%7.2f (%3.0f%%)",
 650            elapsed.sys,
 651            (total->sys == 0 ? 0 : elapsed.sys / total->sys) * 100);
 652 #endif /* HAVE_SYS_TIME */
 653
 654 #ifdef HAVE_WALL_TIME
 655   /* Print wall clock time elapsed.  */
 656   fprintf (fp, "%7.2f (%3.0f%%)",
 657            elapsed.wall,
 658            (total->wall == 0 ? 0 : elapsed.wall / total->wall) * 100);
 659 #endif /* HAVE_WALL_TIME */
 660
 661   /* Print the amount of ggc memory allocated.  */
 662   fprintf (fp, PRsa (6) " (%3.0f%%)",
 663            SIZE_AMOUNT (elapsed.ggc_mem),
 664            (total->ggc_mem == 0
 665             ? 0
 666             : (float) elapsed.ggc_mem / total->ggc_mem) * 100);
 667
 668   putc ('\n', fp);
 669 }
 670
 671 /* Return whether ELAPSED is all zero.  */
 672
 673 bool
 674 timer::all_zero (const timevar_time_def &elapsed)
 675 {
 676   const double tiny = 5e-3;
 677   return (elapsed.user < tiny
 678           && elapsed.sys < tiny
 679           && elapsed.wall < tiny
 680           && elapsed.ggc_mem < GGC_MEM_BOUND);
 681 }
 682
 683 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 684    a special meaning -- it's considered to be the total elapsed time,
 685    for normalizing the others, and is displayed last.  */
 686
 687 void
 688 timer::print (FILE *fp)
 689 {
 690   /* Only print stuff if we have some sort of time information.  */
 691 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 692   unsigned int /* timevar_id_t */ id;
 693   const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
 694   struct timevar_time_def now;
 695
 696   /* Update timing information in case we're calling this from GDB.  */
 697
 698   if (fp == 0)
 699     fp = stderr;
 700
 701   /* What time is it?  */
 702   get_time (&now);
 703
 704   /* If the stack isn't empty, attribute the current elapsed time to
 705      the old topmost element.  */
 706   if (m_stack)
 707     timevar_accumulate (&m_stack->timevar->elapsed, &m_start_time, &now);
 708
 709   /* Reset the start time; from now on, time is attributed to
 710      TIMEVAR.  */
 711   m_start_time = now;
 712
 713   fprintf (fp, "\n%-35s%16s%14s%14s%14s\n", "Time variable", "usr", "sys",
 714            "wall", "GGC");
 715   if (m_jit_client_items)
 716     fputs ("GCC items:\n", fp);
 717   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 718     {
 719       const timevar_def *tv = &m_timevars[(timevar_id_t) id];
 720
 721       /* Don't print the total execution time here; that goes at the
 722          end.  */
 723       if ((timevar_id_t) id == TV_TOTAL)
 724         continue;
 725
 726       /* Don't print timing variables that were never used.  */
 727       if (!tv->used)
 728         continue;
 729
 730       bool any_children_with_time = false;
 731       if (tv->children)
 732         for (child_map_t::iterator i = tv->children->begin ();
 733              i != tv->children->end (); ++i)
 734           if (! all_zero ((*i).second))
 735             {
 736               any_children_with_time = true;
 737               break;
 738             }
 739
 740       /* Don't print timing variables if we're going to get a row of
 741          zeroes.  Unless there are children with non-zero time.  */
 742       if (! any_children_with_time
 743           && all_zero (tv->elapsed))
 744         continue;
 745
 746       print_row (fp, total, tv->name, tv->elapsed);
 747
 748       if (tv->children)
 749         for (child_map_t::iterator i = tv->children->begin ();
 750              i != tv->children->end (); ++i)
 751           {
 752             timevar_def *tv2 = (*i).first;
 753             /* Don't print timing variables if we're going to get a row of
 754                zeroes.  */
 755             if (! all_zero ((*i).second))
 756               {
 757                 char lname[256];
 758                 snprintf (lname, 256, "`- %s", tv2->name);
 759                 print_row (fp, total, lname, (*i).second);
 760               }
 761           }
 762     }
 763   if (m_jit_client_items)
 764     m_jit_client_items->print (fp, total);
 765
 766   /* Print total time.  */
 767   fprintf (fp, " %-35s:", "TOTAL");
 768 #ifdef HAVE_USER_TIME
 769   fprintf (fp, "%7.2f      ", total->user);
 770 #endif
 771 #ifdef HAVE_SYS_TIME
 772   fprintf (fp, "%8.2f      ", total->sys);
 773 #endif
 774 #ifdef HAVE_WALL_TIME
 775   fprintf (fp, "%8.2f      ", total->wall);
 776 #endif
 777   fprintf (fp, PRsa (7) "\n", SIZE_AMOUNT (total->ggc_mem));
 778
 779   if (CHECKING_P || flag_checking)
 780     fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
 781   if (CHECKING_P)
 782     fprintf (fp, "Configure with --enable-checking=release to disable checks.\n");
 783 #ifndef ENABLE_ASSERT_CHECKING
 784   fprintf (fp, "Internal checks disabled; compiler is not suited for release.\n");
 785   fprintf (fp, "Configure with --enable-checking=release to enable checks.\n");
 786 #endif
 787
 788 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 789           || defined (HAVE_WALL_TIME) */
 790
 791   validate_phases (fp);
 792 }
 793
 794 /* Get the name of the topmost item.  For use by jit for validating
 795    inputs to gcc_jit_timer_pop.  */
 796 const char *
 797 timer::get_topmost_item_name () const
 798 {
 799   if (m_stack)
 800     return m_stack->timevar->name;
 801   else
 802     return NULL;
 803 }
 804
 805 /* Prints a message to stderr stating that time elapsed in STR is
 806    TOTAL (given in microseconds).  */
 807
 808 void
 809 print_time (const char *str, long total)
 810 {
 811   long all_time = get_run_time ();
 812   fprintf (stderr,
 813            "time in %s: %ld.%06ld (%ld%%)\n",
 814            str, total / 1000000, total % 1000000,
 815            all_time == 0 ? 0
 816            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 817 }