timevar.c 21.1 KB
Newer Older
1
/* Timing variables for measuring compiler performance.
2
   Copyright (C) 2000-2019 Free Software Foundation, Inc.
3 4
   Contributed by Alex Samuel <samuel@codesourcery.com>

5
This file is part of GCC.
6

7 8
GCC is free software; you can redistribute it and/or modify it under
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 13 14 15
GCC is distributed in the hope that it will be useful, but WITHOUT ANY
WARRANTY; without even the implied warranty of MERCHANTABILITY or
FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
for more details.
16

17
You should have received a copy of the GNU General Public License
18 19
along with GCC; see the file COPYING3.  If not see
<http://www.gnu.org/licenses/>.  */
20 21 22

#include "config.h"
#include "system.h"
23
#include "coretypes.h"
24
#include "timevar.h"
25
#include "options.h"
26

27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63
#ifndef HAVE_CLOCK_T
typedef int clock_t;
#endif

#ifndef HAVE_STRUCT_TMS
struct tms
{
  clock_t tms_utime;
  clock_t tms_stime;
  clock_t tms_cutime;
  clock_t tms_cstime;
};
#endif

#ifndef RUSAGE_SELF
# define RUSAGE_SELF 0
#endif

/* Calculation of scale factor to convert ticks to microseconds.
   We mustn't use CLOCKS_PER_SEC except with clock().  */
#if HAVE_SYSCONF && defined _SC_CLK_TCK
# define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
#else
# ifdef CLK_TCK
#  define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
# else
#  ifdef HZ
#   define TICKS_PER_SECOND HZ  /* traditional UNIX */
#  else
#   define TICKS_PER_SECOND 100 /* often the correct value */
#  endif
# endif
#endif

/* Prefer times to getrusage to clock (each gives successively less
   information).  */
#ifdef HAVE_TIMES
64
# if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
65
  extern clock_t times (struct tms *);
66
# endif
67 68 69 70 71 72
# define USE_TIMES
# define HAVE_USER_TIME
# define HAVE_SYS_TIME
# define HAVE_WALL_TIME
#else
#ifdef HAVE_GETRUSAGE
73
# if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
74
  extern int getrusage (int, struct rusage *);
75
# endif
76 77 78 79 80
# define USE_GETRUSAGE
# define HAVE_USER_TIME
# define HAVE_SYS_TIME
#else
#ifdef HAVE_CLOCK
81
# if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
82
  extern clock_t clock (void);
83
# endif
84 85 86 87 88
# define USE_CLOCK
# define HAVE_USER_TIME
#endif
#endif
#endif
89

90 91 92 93 94
/* libc is very likely to have snuck a call to sysconf() into one of
   the underlying constants, and that can be very slow, so we have to
   precompute them.  Whose wonderful idea was it to make all those
   _constants_ variable at run time, anyway?  */
#ifdef USE_TIMES
95 96
static double ticks_to_msec;
#define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
97 98 99
#endif

#ifdef USE_CLOCK
100 101
static double clocks_to_msec;
#define CLOCKS_TO_MSEC (1 / (double)CLOCKS_PER_SEC)
102 103
#endif

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 110 111 112 113 114 115 116 117
/* Total amount of memory allocated by garbage collector.  */

size_t timevar_ggc_mem_total;

/* The amount of memory that will cause us to report the timevar even
   if the time spent is not significant.  */

#define GGC_MEM_BOUND (1 << 20)

118
/* See timevar.h for an explanation of timing variables.  */
119

120 121 122 123
static void get_time (struct timevar_time_def *);
static void timevar_accumulate (struct timevar_time_def *,
				struct timevar_time_def *,
				struct timevar_time_def *);
124

125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207
/* The implementation of timing events for jit client code, allowing
   arbitrary named items to appear on the timing stack.  */

class timer::named_items
{
 public:
  named_items (timer *t);
  ~named_items ();

  void push (const char *item_name);
  void pop ();
  void print (FILE *fp, const timevar_time_def *total);

 private:
  /* Which timer instance does this relate to?  */
  timer *m_timer;

  /* Dictionary, mapping from item names to timevar_def.
     Note that currently we merely store/compare the raw string
     pointers provided by client code; we don't take a copy,
     or use strcmp.  */
  hash_map <const char *, timer::timevar_def> m_hash_map;

  /* The order in which items were originally inserted.  */
  auto_vec <const char *> m_names;
};

/* The constructor for class timer::named_items.  */

timer::named_items::named_items (timer *t)
: m_timer (t),
  m_hash_map (),
  m_names ()
{
}

/* The destructor for class timer::named_items.  */

timer::named_items::~named_items ()
{
}

/* Push the named item onto the timer stack.  */

void
timer::named_items::push (const char *item_name)
{
  gcc_assert (item_name);

  bool existed;
  timer::timevar_def *def = &m_hash_map.get_or_insert (item_name, &existed);
  if (!existed)
    {
      def->elapsed.user = 0;
      def->elapsed.sys = 0;
      def->elapsed.wall = 0;
      def->name = item_name;
      def->standalone = 0;
      m_names.safe_push (item_name);
    }
  m_timer->push_internal (def);
}

/* Pop the top item from the timer stack.  */

void
timer::named_items::pop ()
{
  m_timer->pop_internal ();
}

/* Print the given client item.  Helper function for timer::print.  */

void
timer::named_items::print (FILE *fp, const timevar_time_def *total)
{
  unsigned int i;
  const char *item_name;
  fprintf (fp, "Client items:\n");
  FOR_EACH_VEC_ELT (m_names, i, item_name)
    {
      timer::timevar_def *def = m_hash_map.get (item_name);
      gcc_assert (def);
208
      m_timer->print_row (fp, total, def->name, def->elapsed);
209 210 211
    }
}

212 213
/* Fill the current times into TIME.  The definition of this function
   also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
Mike Stump committed
214
   HAVE_WALL_TIME macros.  */
215 216

static void
217
get_time (struct timevar_time_def *now)
218
{
219 220 221
  now->user = 0;
  now->sys  = 0;
  now->wall = 0;
222
  now->ggc_mem = timevar_ggc_mem_total;
223

224
  {
225
#ifdef USE_TIMES
226
    struct tms tms;
227 228 229
    now->wall = times (&tms)  * ticks_to_msec;
    now->user = tms.tms_utime * ticks_to_msec;
    now->sys  = tms.tms_stime * ticks_to_msec;
230 231
#endif
#ifdef USE_GETRUSAGE
232
    struct rusage rusage;
233
    getrusage (RUSAGE_SELF, &rusage);
234 235
    now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
    now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
236 237
#endif
#ifdef USE_CLOCK
238
    now->user = clock () * clocks_to_msec;
239
#endif
240
  }
241
}
242 243 244

/* Add the difference between STOP_TIME and START_TIME to TIMER.  */

Kazu Hirata committed
245
static void
246 247 248
timevar_accumulate (struct timevar_time_def *timer,
		    struct timevar_time_def *start_time,
		    struct timevar_time_def *stop_time)
249 250 251 252
{
  timer->user += stop_time->user - start_time->user;
  timer->sys += stop_time->sys - start_time->sys;
  timer->wall += stop_time->wall - start_time->wall;
253
  timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
254 255
}

256
/* Class timer's constructor.  */
257

258 259 260
timer::timer () :
  m_stack (NULL),
  m_unused_stack_instances (NULL),
261 262
  m_start_time (),
  m_jit_client_items (NULL)
263 264
{
  /* Zero all elapsed times.  */
265
  memset (m_timevars, 0, sizeof (m_timevars));
266 267

  /* Initialize the names of timing variables.  */
268
#define DEFTIMEVAR(identifier__, name__) \
269
  m_timevars[identifier__].name = name__;
270 271
#include "timevar.def"
#undef DEFTIMEVAR
272

273 274
  /* Initialize configuration-specific state.
     Ideally this would be one-time initialization.  */
275 276 277 278 279 280
#ifdef USE_TIMES
  ticks_to_msec = TICKS_TO_MSEC;
#endif
#ifdef USE_CLOCK
  clocks_to_msec = CLOCKS_TO_MSEC;
#endif
281 282
}

283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298
/* Class timer's destructor.  */

timer::~timer ()
{
  timevar_stack_def *iter, *next;

  for (iter = m_stack; iter; iter = next)
    {
      next = iter->next;
      free (iter);
    }
  for (iter = m_unused_stack_instances; iter; iter = next)
    {
      next = iter->next;
      free (iter);
    }
299 300
  for (unsigned i = 0; i < TIMEVAR_LAST; ++i)
    delete m_timevars[i].children;
301 302 303 304

  delete m_jit_client_items;
}

305 306 307 308 309 310 311 312 313 314 315
/* Initialize timing variables.  */

void
timevar_init (void)
{
  if (g_timer)
    return;

  g_timer = new timer ();
}

316 317 318
/* Push TIMEVAR onto the timing stack.  No further elapsed time is
   attributed to the previous topmost timing variable on the stack;
   subsequent elapsed time is attributed to TIMEVAR, until it is
Kazu Hirata committed
319
   popped or another element is pushed on top.
320 321 322 323

   TIMEVAR cannot be running as a standalone timer.  */

void
324
timer::push (timevar_id_t timevar)
325
{
326
  struct timevar_def *tv = &m_timevars[timevar];
327 328 329 330 331 332 333 334 335
  push_internal (tv);
}

/* Push TV onto the timing stack, either one of the builtin ones
   for a timevar_id_t, or one provided by client code to libgccjit.  */

void
timer::push_internal (struct timevar_def *tv)
{
336 337 338
  struct timevar_stack_def *context;
  struct timevar_time_def now;

339 340
  gcc_assert (tv);

341 342 343
  /* Mark this timing variable as used.  */
  tv->used = 1;

344
  /* Can't push a standalone timer.  */
345
  gcc_assert (!tv->standalone);
346 347 348 349 350 351

  /* What time is it?  */
  get_time (&now);

  /* If the stack isn't empty, attribute the current elapsed time to
     the old topmost element.  */
352 353
  if (m_stack)
    timevar_accumulate (&m_stack->timevar->elapsed, &m_start_time, &now);
354 355

  /* Reset the start time; from now on, time is attributed to
356
     TIMEVAR.  */
357
  m_start_time = now;
358

359 360
  /* See if we have a previously-allocated stack instance.  If so,
     take it off the list.  If not, malloc a new one.  */
361
  if (m_unused_stack_instances != NULL)
362
    {
363 364
      context = m_unused_stack_instances;
      m_unused_stack_instances = m_unused_stack_instances->next;
365 366
    }
  else
367
    context = XNEW (struct timevar_stack_def);
368 369

  /* Fill it in and put it on the stack.  */
370
  context->timevar = tv;
371 372
  context->next = m_stack;
  m_stack = context;
373 374 375 376 377 378 379 380 381
}

/* Pop the topmost timing variable element off the timing stack.  The
   popped variable must be TIMEVAR.  Elapsed time since the that
   element was pushed on, or since it was last exposed on top of the
   stack when the element above it was popped off, is credited to that
   timing variable.  */

void
382
timer::pop (timevar_id_t timevar)
383
{
384 385 386 387 388 389 390 391 392 393 394
  gcc_assert (&m_timevars[timevar] == m_stack->timevar);

  pop_internal ();
}

/* Pop the topmost item from the stack, either one of the builtin ones
   for a timevar_id_t, or one provided by client code to libgccjit.  */

void
timer::pop_internal ()
{
395
  struct timevar_time_def now;
396
  struct timevar_stack_def *popped = m_stack;
397

398 399 400 401
  /* What time is it?  */
  get_time (&now);

  /* Attribute the elapsed time to the element we're popping.  */
402
  timevar_accumulate (&popped->timevar->elapsed, &m_start_time, &now);
403

404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419
  /* Take the item off the stack.  */
  m_stack = m_stack->next;

  /* Record the elapsed sub-time to the parent as well.  */
  if (m_stack && time_report_details)
    {
      if (! m_stack->timevar->children)
	m_stack->timevar->children = new child_map_t (5);
      bool existed_p;
      timevar_time_def &time
	= m_stack->timevar->children->get_or_insert (popped->timevar, &existed_p);
      if (! existed_p)
	memset (&time, 0, sizeof (timevar_time_def));
      timevar_accumulate (&time, &m_start_time, &now);
    }

420 421
  /* Reset the start time; from now on, time is attributed to the
     element just exposed on the stack.  */
422
  m_start_time = now;
423

424 425
  /* Don't delete the stack element; instead, add it to the list of
     unused elements for later use.  */
426 427
  popped->next = m_unused_stack_instances;
  m_unused_stack_instances = popped;
428 429 430 431 432 433 434
}

/* Start timing TIMEVAR independently of the timing stack.  Elapsed
   time until timevar_stop is called for the same timing variable is
   attributed to TIMEVAR.  */

void
435
timevar_start (timevar_id_t timevar)
436
{
437
  if (!g_timer)
438 439
    return;

440 441 442 443 444 445 446 447 448 449
  g_timer->start (timevar);
}

/* See timevar_start above.  */

void
timer::start (timevar_id_t timevar)
{
  struct timevar_def *tv = &m_timevars[timevar];

450 451 452
  /* Mark this timing variable as used.  */
  tv->used = 1;

453 454
  /* Don't allow the same timing variable to be started more than
     once.  */
455
  gcc_assert (!tv->standalone);
456 457 458 459 460 461 462 463 464
  tv->standalone = 1;

  get_time (&tv->start_time);
}

/* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
   is attributed to it.  */

void
465
timevar_stop (timevar_id_t timevar)
466
{
467
  if (!g_timer)
468 469
    return;

470 471 472 473 474 475 476 477 478 479 480
  g_timer->stop (timevar);
}

/* See timevar_stop above.  */

void
timer::stop (timevar_id_t timevar)
{
  struct timevar_def *tv = &m_timevars[timevar];
  struct timevar_time_def now;

481
  /* TIMEVAR must have been started via timevar_start.  */
482
  gcc_assert (tv->standalone);
483
  tv->standalone = 0; /* Enable a restart.  */
484 485 486 487 488

  get_time (&now);
  timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
}

489 490 491 492 493 494 495 496 497 498

/* Conditionally start timing TIMEVAR independently of the timing stack.
   If the timer is already running, leave it running and return true.
   Otherwise, start the timer and return false.
   Elapsed time until the corresponding timevar_cond_stop
   is called for the same timing variable is attributed to TIMEVAR.  */

bool
timevar_cond_start (timevar_id_t timevar)
{
499
  if (!g_timer)
500 501
    return false;

502 503 504 505 506 507 508 509 510 511
  return g_timer->cond_start (timevar);
}

/* See timevar_cond_start above.  */

bool
timer::cond_start (timevar_id_t timevar)
{
  struct timevar_def *tv = &m_timevars[timevar];

512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533
  /* Mark this timing variable as used.  */
  tv->used = 1;

  if (tv->standalone)
    return true;  /* The timevar is already running.  */

  /* Don't allow the same timing variable
     to be unconditionally started more than once.  */
  tv->standalone = 1;

  get_time (&tv->start_time);
  return false;  /* The timevar was not already running.  */
}

/* Conditionally stop timing TIMEVAR.  The RUNNING parameter must come
   from the return value of a dynamically matching timevar_cond_start.
   If the timer had already been RUNNING, do nothing.  Otherwise, time
   elapsed since timevar_cond_start was called is attributed to it.  */

void
timevar_cond_stop (timevar_id_t timevar, bool running)
{
534 535 536 537 538 539 540 541 542 543 544
  if (!g_timer || running)
    return;

  g_timer->cond_stop (timevar);
}

/* See timevar_cond_stop above.  */

void
timer::cond_stop (timevar_id_t timevar)
{
545 546 547
  struct timevar_def *tv;
  struct timevar_time_def now;

548
  tv = &m_timevars[timevar];
549 550 551 552 553 554 555 556 557

  /* TIMEVAR must have been started via timevar_cond_start.  */
  gcc_assert (tv->standalone);
  tv->standalone = 0; /* Enable a restart.  */

  get_time (&now);
  timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
}

558 559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578 579
/* Push the named item onto the timing stack.  */

void
timer::push_client_item (const char *item_name)
{
  gcc_assert (item_name);

  /* Lazily create the named_items instance.  */
  if (!m_jit_client_items)
    m_jit_client_items = new named_items (this);

  m_jit_client_items->push (item_name);
}

/* Pop the top-most client item from the timing stack.  */

void
timer::pop_client_item ()
{
  gcc_assert (m_jit_client_items);
  m_jit_client_items->pop ();
}
580

581 582
/* Validate that phase times are consistent.  */

583 584
void
timer::validate_phases (FILE *fp) const
585 586
{
  unsigned int /* timevar_id_t */ id;
587
  const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
588 589 590
  double phase_user = 0.0;
  double phase_sys = 0.0;
  double phase_wall = 0.0;
591
  size_t phase_ggc_mem = 0;
592 593 594 595 596
  static char phase_prefix[] = "phase ";
  const double tolerance = 1.000001;  /* One part in a million.  */

  for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
    {
597
      const timevar_def *tv = &m_timevars[(timevar_id_t) id];
598 599 600 601 602 603 604 605 606 607 608 609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625

      /* 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)
626 627
	fprintf (fp, "ggc_mem %24lu > %24lu\n", (unsigned long)phase_ggc_mem,
		 (unsigned long)total->ggc_mem);
628 629 630 631
      gcc_unreachable ();
    }
}

632 633 634 635 636
/* Helper function for timer::print.  */

void
timer::print_row (FILE *fp,
		  const timevar_time_def *total,
637
		  const char *name, const timevar_time_def &elapsed)
638 639
{
  /* The timing variable name.  */
640
  fprintf (fp, " %-35s:", name);
641 642 643

#ifdef HAVE_USER_TIME
  /* Print user-mode time for this process.  */
644
  fprintf (fp, "%7.2f (%3.0f%%)",
645 646
	   elapsed.user,
	   (total->user == 0 ? 0 : elapsed.user / total->user) * 100);
647 648 649 650
#endif /* HAVE_USER_TIME */

#ifdef HAVE_SYS_TIME
  /* Print system-mode time for this process.  */
651
  fprintf (fp, "%7.2f (%3.0f%%)",
652 653
	   elapsed.sys,
	   (total->sys == 0 ? 0 : elapsed.sys / total->sys) * 100);
654 655 656 657
#endif /* HAVE_SYS_TIME */

#ifdef HAVE_WALL_TIME
  /* Print wall clock time elapsed.  */
658
  fprintf (fp, "%7.2f (%3.0f%%)",
659 660
	   elapsed.wall,
	   (total->wall == 0 ? 0 : elapsed.wall / total->wall) * 100);
661 662 663
#endif /* HAVE_WALL_TIME */

  /* Print the amount of ggc memory allocated.  */
664
  fprintf (fp, "%8u kB (%3.0f%%)",
665
	   (unsigned) (elapsed.ggc_mem >> 10),
666 667
	   (total->ggc_mem == 0
	    ? 0
668
	    : (float) elapsed.ggc_mem / total->ggc_mem) * 100);
669 670 671

  putc ('\n', fp);
}
672

673 674 675 676 677 678 679 680 681 682 683 684
/* Return whether ELAPSED is all zero.  */

bool
timer::all_zero (const timevar_time_def &elapsed)
{
  const double tiny = 5e-3;
  return (elapsed.user < tiny
	  && elapsed.sys < tiny
	  && elapsed.wall < tiny
	  && elapsed.ggc_mem < GGC_MEM_BOUND);
}

685 686 687 688 689
/* 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.  */

void
690
timer::print (FILE *fp)
691 692 693
{
  /* Only print stuff if we have some sort of time information.  */
#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
694
  unsigned int /* timevar_id_t */ id;
695
  const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
696
  struct timevar_time_def now;
697

698 699 700 701 702 703 704 705 706 707
  /* Update timing information in case we're calling this from GDB.  */

  if (fp == 0)
    fp = stderr;

  /* What time is it?  */
  get_time (&now);

  /* If the stack isn't empty, attribute the current elapsed time to
     the old topmost element.  */
708 709
  if (m_stack)
    timevar_accumulate (&m_stack->timevar->elapsed, &m_start_time, &now);
710 711

  /* Reset the start time; from now on, time is attributed to
712
     TIMEVAR.  */
713
  m_start_time = now;
714

715
  fprintf (fp, "\n%-35s%16s%14s%14s%18s\n", "Time variable", "usr", "sys",
716
	   "wall", "GGC");
717 718
  if (m_jit_client_items)
    fputs ("GCC items:\n", fp);
719
  for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
720
    {
721
      const timevar_def *tv = &m_timevars[(timevar_id_t) id];
722 723 724

      /* Don't print the total execution time here; that goes at the
	 end.  */
725
      if ((timevar_id_t) id == TV_TOTAL)
726 727
	continue;

728 729 730 731
      /* Don't print timing variables that were never used.  */
      if (!tv->used)
	continue;

732 733 734 735 736 737 738 739 740 741
      bool any_children_with_time = false;
      if (tv->children)
	for (child_map_t::iterator i = tv->children->begin ();
	     i != tv->children->end (); ++i)
	  if (! all_zero ((*i).second))
	    {
	      any_children_with_time = true;
	      break;
	    }

742
      /* Don't print timing variables if we're going to get a row of
743 744 745
         zeroes.  Unless there are children with non-zero time.  */
      if (! any_children_with_time
	  && all_zero (tv->elapsed))
746 747
	continue;

748 749 750 751 752 753 754 755 756 757 758 759 760 761 762 763
      print_row (fp, total, tv->name, tv->elapsed);

      if (tv->children)
	for (child_map_t::iterator i = tv->children->begin ();
	     i != tv->children->end (); ++i)
	  {
	    timevar_def *tv2 = (*i).first;
	    /* Don't print timing variables if we're going to get a row of
	       zeroes.  */
	    if (! all_zero ((*i).second))
	      {
		char lname[256];
		snprintf (lname, 256, "`- %s", tv2->name);
		print_row (fp, total, lname, (*i).second);
	      }
	  }
764
    }
765 766
  if (m_jit_client_items)
    m_jit_client_items->print (fp, total);
767 768

  /* Print total time.  */
769
  fprintf (fp, " %-35s:", "TOTAL");
770
#ifdef HAVE_USER_TIME
771
  fprintf (fp, "%7.2f      ", total->user);
Kazu Hirata committed
772
#endif
773
#ifdef HAVE_SYS_TIME
774
  fprintf (fp, "%8.2f      ", total->sys);
775 776
#endif
#ifdef HAVE_WALL_TIME
777
  fprintf (fp, "%8.2f      ", total->wall);
778
#endif
779
  fprintf (fp, "%9u kB\n", (unsigned) (total->ggc_mem >> 10));
Kazu Hirata committed
780

781 782 783 784
  if (CHECKING_P || flag_checking)
    fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
  if (CHECKING_P)
    fprintf (fp, "Configure with --enable-checking=release to disable checks.\n");
785 786 787
#ifndef ENABLE_ASSERT_CHECKING
  fprintf (fp, "Internal checks disabled; compiler is not suited for release.\n");
  fprintf (fp, "Configure with --enable-checking=release to enable checks.\n");
788 789
#endif

Kazu Hirata committed
790
#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
791
	  || defined (HAVE_WALL_TIME) */
792 793

  validate_phases (fp);
794 795
}

796 797 798 799 800 801 802 803 804 805 806
/* Get the name of the topmost item.  For use by jit for validating
   inputs to gcc_jit_timer_pop.  */
const char *
timer::get_topmost_item_name () const
{
  if (m_stack)
    return m_stack->timevar->name;
  else
    return NULL;
}

807 808 809 810
/* Prints a message to stderr stating that time elapsed in STR is
   TOTAL (given in microseconds).  */

void
811
print_time (const char *str, long total)
812 813 814
{
  long all_time = get_run_time ();
  fprintf (stderr,
815
	   "time in %s: %ld.%06ld (%ld%%)\n",
816
	   str, total / 1000000, total % 1000000,
Kazu Hirata committed
817 818
	   all_time == 0 ? 0
	   : (long) (((100.0 * (double) total) / (double) all_time) + .5));
819
}