gcc/timevar.c

   1 /* Timing variables for measuring compiler performance.
   2    Copyright (C) 2000, 2003 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 2, 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 COPYING.  If not, write to the Free
  19 Software Foundation, 59 Temple Place - Suite 330, Boston, MA
  20 02111-1307, USA.  */
  21
  22 #include "config.h"
  23 #include "system.h"
  24 #ifdef HAVE_SYS_TIMES_H
  25 # include <sys/times.h>
  26 #endif
  27 #ifdef HAVE_SYS_RESOURCE_H
  28 #include <sys/resource.h>
  29 #endif
  30 #include "coretypes.h"
  31 #include "tm.h"
  32 #include "intl.h"
  33 #include "rtl.h"
  34 #include "toplev.h"
  35
  36 #ifndef HAVE_CLOCK_T
  37 typedef int clock_t;
  38 #endif
  39
  40 #ifndef HAVE_STRUCT_TMS
  41 struct tms
  42 {
  43   clock_t tms_utime;
  44   clock_t tms_stime;
  45   clock_t tms_cutime;
  46   clock_t tms_cstime;
  47 };
  48 #endif
  49
  50 #ifndef RUSAGE_SELF
  51 # define RUSAGE_SELF 0
  52 #endif
  53
  54 /* Calculation of scale factor to convert ticks to microseconds.
  55    We mustn't use CLOCKS_PER_SEC except with clock().  */
  56 #if HAVE_SYSCONF && defined _SC_CLK_TCK
  57 # define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
  58 #else
  59 # ifdef CLK_TCK
  60 #  define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
  61 # else
  62 #  ifdef HZ
  63 #   define TICKS_PER_SECOND HZ  /* traditional UNIX */
  64 #  else
  65 #   define TICKS_PER_SECOND 100 /* often the correct value */
  66 #  endif
  67 # endif
  68 #endif
  69
  70 /* Prefer times to getrusage to clock (each gives successively less
  71    information).  */
  72 #ifdef HAVE_TIMES
  73 # if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
  74   extern clock_t times PARAMS ((struct tms *));
  75 # endif
  76 # define USE_TIMES
  77 # define HAVE_USER_TIME
  78 # define HAVE_SYS_TIME
  79 # define HAVE_WALL_TIME
  80 #else
  81 #ifdef HAVE_GETRUSAGE
  82 # if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
  83   extern int getrusage PARAMS ((int, struct rusage *));
  84 # endif
  85 # define USE_GETRUSAGE
  86 # define HAVE_USER_TIME
  87 # define HAVE_SYS_TIME
  88 #else
  89 #ifdef HAVE_CLOCK
  90 # if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
  91   extern clock_t clock PARAMS ((void));
  92 # endif
  93 # define USE_CLOCK
  94 # define HAVE_USER_TIME
  95 #endif
  96 #endif
  97 #endif
  98
  99 /* libc is very likely to have snuck a call to sysconf() into one of
 100    the underlying constants, and that can be very slow, so we have to
 101    precompute them.  Whose wonderful idea was it to make all those
 102    _constants_ variable at run time, anyway?  */
 103 #ifdef USE_TIMES
 104 static double ticks_to_msec;
 105 #define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
 106 #endif
 107
 108 #ifdef USE_CLOCK
 109 static double clocks_to_msec;
 110 #define CLOCKS_TO_MSEC (1 / (double)CLOCKS_PER_SEC)
 111 #endif
 112
 113 #include "flags.h"
 114 #include "timevar.h"
 115
 116 static bool timevar_enable;
 117
 118 /* See timevar.h for an explanation of timing variables.  */
 119
 120 /* A timing variable.  */
 121
 122 struct timevar_def
 123 {
 124   /* Elapsed time for this variable.  */
 125   struct timevar_time_def elapsed;
 126
 127   /* If this variable is timed independently of the timing stack,
 128      using timevar_start, this contains the start time.  */
 129   struct timevar_time_def start_time;
 130
 131   /* The name of this timing variable.  */
 132   const char *name;
 133
 134   /* Nonzero if this timing variable is running as a standalone
 135      timer.  */
 136   unsigned standalone : 1;
 137
 138   /* Nonzero if this timing variable was ever started or pushed onto
 139      the timing stack.  */
 140   unsigned used : 1;
 141 };
 142
 143 /* An element on the timing stack.  Elapsed time is attributed to the
 144    topmost timing variable on the stack.  */
 145
 146 struct timevar_stack_def
 147 {
 148   /* The timing variable at this stack level.  */
 149   struct timevar_def *timevar;
 150
 151   /* The next lower timing variable context in the stack.  */
 152   struct timevar_stack_def *next;
 153 };
 154
 155 /* Declared timing variables.  Constructed from the contents of
 156    timevar.def.  */
 157 static struct timevar_def timevars[TIMEVAR_LAST];
 158
 159 /* The top of the timing stack.  */
 160 static struct timevar_stack_def *stack;
 161
 162 /* A list of unused (i.e. allocated and subsequently popped)
 163    timevar_stack_def instances.  */
 164 static struct timevar_stack_def *unused_stack_instances;
 165
 166 /* The time at which the topmost element on the timing stack was
 167    pushed.  Time elapsed since then is attributed to the topmost
 168    element.  */
 169 static struct timevar_time_def start_time;
 170
 171 static void get_time
 172   PARAMS ((struct timevar_time_def *));
 173 static void timevar_accumulate
 174   PARAMS ((struct timevar_time_def *, struct timevar_time_def *,
 175            struct timevar_time_def *));
 176
 177 /* Fill the current times into TIME.  The definition of this function
 178    also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
 179    HAVE_WALL_TIME macros.  */
 180
 181 static void
 182 get_time (now)
 183      struct timevar_time_def *now;
 184 {
 185   now->user = 0;
 186   now->sys  = 0;
 187   now->wall = 0;
 188
 189   if (!timevar_enable)
 190     return;
 191
 192   {
 193 #ifdef USE_TIMES
 194     struct tms tms;
 195     now->wall = times (&tms)  * ticks_to_msec;
 196     now->user = tms.tms_utime * ticks_to_msec;
 197     now->sys  = tms.tms_stime * ticks_to_msec;
 198 #endif
 199 #ifdef USE_GETRUSAGE
 200     struct rusage rusage;
 201     getrusage (RUSAGE_SELF, &rusage);
 202     now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
 203     now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
 204 #endif
 205 #ifdef USE_CLOCK
 206     now->user = clock () * clocks_to_msec;
 207 #endif
 208   }
 209 }
 210
 211 /* Add the difference between STOP_TIME and START_TIME to TIMER.  */
 212
 213 static void
 214 timevar_accumulate (timer, start_time, stop_time)
 215      struct timevar_time_def *timer;
 216      struct timevar_time_def *start_time;
 217      struct timevar_time_def *stop_time;
 218 {
 219   timer->user += stop_time->user - start_time->user;
 220   timer->sys += stop_time->sys - start_time->sys;
 221   timer->wall += stop_time->wall - start_time->wall;
 222 }
 223
 224 /* Initialize timing variables.  */
 225
 226 void
 227 timevar_init ()
 228 {
 229   timevar_enable = true;
 230
 231   /* Zero all elapsed times.  */
 232   memset ((void *) timevars, 0, sizeof (timevars));
 233
 234   /* Initialize the names of timing variables.  */
 235 #define DEFTIMEVAR(identifier__, name__) \
 236   timevars[identifier__].name = name__;
 237 #include "timevar.def"
 238 #undef DEFTIMEVAR
 239
 240 #ifdef USE_TIMES
 241   ticks_to_msec = TICKS_TO_MSEC;
 242 #endif
 243 #ifdef USE_CLOCK
 244   clocks_to_msec = CLOCKS_TO_MSEC;
 245 #endif
 246 }
 247
 248 /* Push TIMEVAR onto the timing stack.  No further elapsed time is
 249    attributed to the previous topmost timing variable on the stack;
 250    subsequent elapsed time is attributed to TIMEVAR, until it is
 251    popped or another element is pushed on top.
 252
 253    TIMEVAR cannot be running as a standalone timer.  */
 254
 255 void
 256 timevar_push (timevar)
 257      timevar_id_t timevar;
 258 {
 259   struct timevar_def *tv = &timevars[timevar];
 260   struct timevar_stack_def *context;
 261   struct timevar_time_def now;
 262
 263   if (!timevar_enable)
 264     return;
 265
 266   /* Mark this timing variable as used.  */
 267   tv->used = 1;
 268
 269   /* Can't push a standalone timer.  */
 270   if (tv->standalone)
 271     abort ();
 272
 273   /* What time is it?  */
 274   get_time (&now);
 275
 276   /* If the stack isn't empty, attribute the current elapsed time to
 277      the old topmost element.  */
 278   if (stack)
 279     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 280
 281   /* Reset the start time; from now on, time is attributed to
 282      TIMEVAR.  */
 283   start_time = now;
 284
 285   /* See if we have a previously-allocated stack instance.  If so,
 286      take it off the list.  If not, malloc a new one.  */
 287   if (unused_stack_instances != NULL)
 288     {
 289       context = unused_stack_instances;
 290       unused_stack_instances = unused_stack_instances->next;
 291     }
 292   else
 293     context = (struct timevar_stack_def *)
 294       xmalloc (sizeof (struct timevar_stack_def));
 295
 296   /* Fill it in and put it on the stack.  */
 297   context->timevar = tv;
 298   context->next = stack;
 299   stack = context;
 300 }
 301
 302 /* Pop the topmost timing variable element off the timing stack.  The
 303    popped variable must be TIMEVAR.  Elapsed time since the that
 304    element was pushed on, or since it was last exposed on top of the
 305    stack when the element above it was popped off, is credited to that
 306    timing variable.  */
 307
 308 void
 309 timevar_pop (timevar)
 310      timevar_id_t timevar;
 311 {
 312   struct timevar_time_def now;
 313   struct timevar_stack_def *popped = stack;
 314
 315   if (!timevar_enable)
 316     return;
 317
 318   if (&timevars[timevar] != stack->timevar)
 319     {
 320       sorry ("cannot timevar_pop '%s' when top of timevars stack is '%s'",
 321              timevars[timevar].name, stack->timevar->name);
 322       abort ();
 323     }
 324
 325   /* What time is it?  */
 326   get_time (&now);
 327
 328   /* Attribute the elapsed time to the element we're popping.  */
 329   timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
 330
 331   /* Reset the start time; from now on, time is attributed to the
 332      element just exposed on the stack.  */
 333   start_time = now;
 334
 335   /* Take the item off the stack.  */
 336   stack = stack->next;
 337
 338   /* Don't delete the stack element; instead, add it to the list of
 339      unused elements for later use.  */
 340   popped->next = unused_stack_instances;
 341   unused_stack_instances = popped;
 342 }
 343
 344 /* Start timing TIMEVAR independently of the timing stack.  Elapsed
 345    time until timevar_stop is called for the same timing variable is
 346    attributed to TIMEVAR.  */
 347
 348 void
 349 timevar_start (timevar)
 350      timevar_id_t timevar;
 351 {
 352   struct timevar_def *tv = &timevars[timevar];
 353
 354   if (!timevar_enable)
 355     return;
 356
 357   /* Mark this timing variable as used.  */
 358   tv->used = 1;
 359
 360   /* Don't allow the same timing variable to be started more than
 361      once.  */
 362   if (tv->standalone)
 363     abort ();
 364   tv->standalone = 1;
 365
 366   get_time (&tv->start_time);
 367 }
 368
 369 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 370    is attributed to it.  */
 371
 372 void
 373 timevar_stop (timevar)
 374      timevar_id_t timevar;
 375 {
 376   struct timevar_def *tv = &timevars[timevar];
 377   struct timevar_time_def now;
 378
 379   if (!timevar_enable)
 380     return;
 381
 382   /* TIMEVAR must have been started via timevar_start.  */
 383   if (!tv->standalone)
 384     abort ();
 385
 386   get_time (&now);
 387   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 388 }
 389
 390 /* Fill the elapsed time for TIMEVAR into ELAPSED.  Returns
 391    update-to-date information even if TIMEVAR is currently running.  */
 392
 393 void
 394 timevar_get (timevar, elapsed)
 395      timevar_id_t timevar;
 396      struct timevar_time_def *elapsed;
 397 {
 398   struct timevar_def *tv = &timevars[timevar];
 399   struct timevar_time_def now;
 400
 401   *elapsed = tv->elapsed;
 402
 403   /* Is TIMEVAR currently running as a standalone timer?  */
 404   if (tv->standalone)
 405     {
 406       get_time (&now);
 407       timevar_accumulate (elapsed, &tv->start_time, &now);
 408     }
 409   /* Or is TIMEVAR at the top of the timer stack?  */
 410   else if (stack->timevar == tv)
 411     {
 412       get_time (&now);
 413       timevar_accumulate (elapsed, &start_time, &now);
 414     }
 415 }
 416
 417 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 418    a special meaning -- it's considered to be the total elapsed time,
 419    for normalizing the others, and is displayed last.  */
 420
 421 void
 422 timevar_print (fp)
 423      FILE *fp;
 424 {
 425   /* Only print stuff if we have some sort of time information.  */
 426 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 427   unsigned int /* timevar_id_t */ id;
 428   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
 429   struct timevar_time_def now;
 430
 431   if (!timevar_enable)
 432     return;
 433
 434   /* Update timing information in case we're calling this from GDB.  */
 435
 436   if (fp == 0)
 437     fp = stderr;
 438
 439   /* What time is it?  */
 440   get_time (&now);
 441
 442   /* If the stack isn't empty, attribute the current elapsed time to
 443      the old topmost element.  */
 444   if (stack)
 445     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 446
 447   /* Reset the start time; from now on, time is attributed to
 448      TIMEVAR.  */
 449   start_time = now;
 450
 451   fputs (_("\nExecution times (seconds)\n"), fp);
 452   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 453     {
 454       struct timevar_def *tv = &timevars[(timevar_id_t) id];
 455       const double tiny = 5e-3;
 456
 457       /* Don't print the total execution time here; that goes at the
 458          end.  */
 459       if ((timevar_id_t) id == TV_TOTAL)
 460         continue;
 461
 462       /* Don't print timing variables that were never used.  */
 463       if (!tv->used)
 464         continue;
 465
 466       /* Don't print timing variables if we're going to get a row of
 467          zeroes.  */
 468       if (tv->elapsed.user < tiny
 469           && tv->elapsed.sys < tiny
 470           && tv->elapsed.wall < tiny)
 471         continue;
 472
 473       /* The timing variable name.  */
 474       fprintf (fp, " %-22s:", tv->name);
 475
 476 #ifdef HAVE_USER_TIME
 477       /* Print user-mode time for this process.  */
 478       fprintf (fp, "%7.2f (%2.0f%%) usr",
 479                tv->elapsed.user,
 480                (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
 481 #endif /* HAVE_USER_TIME */
 482
 483 #ifdef HAVE_SYS_TIME
 484       /* Print system-mode time for this process.  */
 485       fprintf (fp, "%7.2f (%2.0f%%) sys",
 486                tv->elapsed.sys,
 487                (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
 488 #endif /* HAVE_SYS_TIME */
 489
 490 #ifdef HAVE_WALL_TIME
 491       /* Print wall clock time elapsed.  */
 492       fprintf (fp, "%7.2f (%2.0f%%) wall",
 493                tv->elapsed.wall,
 494                (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
 495 #endif /* HAVE_WALL_TIME */
 496
 497       putc ('\n', fp);
 498     }
 499
 500   /* Print total time.  */
 501   fputs (_(" TOTAL                 :"), fp);
 502 #ifdef HAVE_USER_TIME
 503   fprintf (fp, "%7.2f          ", total->user);
 504 #endif
 505 #ifdef HAVE_SYS_TIME
 506   fprintf (fp, "%7.2f          ", total->sys);
 507 #endif
 508 #ifdef HAVE_WALL_TIME
 509   fprintf (fp, "%7.2f\n", total->wall);
 510 #endif
 511
 512 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 513           || defined (HAVE_WALL_TIME) */
 514 }
 515
 516 /* Prints a message to stderr stating that time elapsed in STR is
 517    TOTAL (given in microseconds).  */
 518
 519 void
 520 print_time (str, total)
 521      const char *str;
 522      long total;
 523 {
 524   long all_time = get_run_time ();
 525   fprintf (stderr,
 526            _("time in %s: %ld.%06ld (%ld%%)\n"),
 527            str, total / 1000000, total % 1000000,
 528            all_time == 0 ? 0
 529            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 530 }