lib/timevar.c

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