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