lib/timevar.c

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