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