gcc/timevar.c

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